datadog / pg_tracing Goto Github PK

Distributed Tracing for PostgreSQL

License: MIT License

Dockerfile 1.18% Makefile 1.14% PLpgSQL 15.05% C 82.64%

pg_tracing's Introduction

pg_tracing

pg_tracing is a PostgreSQL extension allows to generate server-side spans for distributed tracing.

When pg_tracing is active, it generates spans on sampled queries. To access these spans, the extension provides two views: pg_tracing_consume_spans and pg_tracing_peek_spans. The utility functions pg_tracing_reset and pg_tracing_info provide ways to read and reset extension's statistics. These are not available globally but can be enabled for a specific database with CREATE EXTENSION pg_tracing.

Trace propagation currently relies on SQLCommenter. More mechanisms will be added in the future.

Warning

This extension is still in early development and may be unstable.

PostgreSQL Version Compatibility

pg_tracing only supports PostgreSQL 15 and 16 for the moment.

Generated Spans

pg_tracing generates spans for the following events:

PostgreSQL internal functions: Planner, ProcessUtility, ExecutorRun, ExecutorFinish
Statements: SELECT, INSERT, DELETE...
Utility Statements: ALTER, SHOW, TRUNCATE, CALL...
Execution Plan: A span is created for each node of the execution plan (SeqScan, NestedLoop, HashJoin...)
Nested queries: Statements invoked within another statement (like a function)
Triggers: Statements executed through BEFORE and AFTER trigger are tracked
Parallel Workers: Processes created to handle queries like Parallel SeqScans are tracked

Documentation

The following list of files is found in the doc folder of the pg_tracing github repository. For installation instructions, please see the next section of this README.

File	Description
pg_tracing.md	Main reference documentation for pg_tracing.

Installation

From Source

pg_tracing can be compiled against an installed copy of PostgreSQL with development packages using PGXS.

To compile and install the extension, run:

git clone https://github.com/DataDog/pg_tracing.git
cd pg_tracing
make install

Setup

The extension must be loaded by adding pg_tracing to the shared_preload_libraries in postgresql.conf. A server restart is needed to add or remove the extension.

# postgresql.conf
shared_preload_libraries = 'pg_tracing'

compute_query_id = on
pg_tracing.max_span = 10000
pg_tracing.track = all

The extension requires additional shared memory proportional to pg_tracing.max_span. Note that this memory is consumed whenever the extension is loaded, even if no spans are generated.

When pg_tracing is active, it generates spans on sampled queries. To access these spans, the extension provides two views: pg_tracing_consume_spans and pg_tracing_peek_spans. The utility functions pg_tracing_reset and pg_tracing_info provide ways to read and reset extension's statistics. These are not available globally but can be enabled for a specific database with CREATE EXTENSION pg_tracing.

Usage

Trace context can be propagated through SQLCommenter. By default, all queries with a SQLCommenter with a sampled flag enabled will generate spans.

-- Query with trace context and sampled flag enable
/*traceparent='00-00000000000000000000000000000123-0000000000000123-01'*/ SELECT 1;

-- Check the generated spans
select trace_id, parent_id, span_id, span_start, span_end, span_type, span_operation from pg_tracing_consume_spans order by span_start;
             trace_id             |    parent_id     |     span_id      |          span_start           |           span_end            |  span_type   | span_operation
----------------------------------+------------------+------------------+-------------------------------+-------------------------------+--------------+----------------
 00000000000000000000000000000123 | 0000000000000123 | 4268a4281c5316dd | 2024-03-19 13:46:43.97958+00  | 2024-03-19 13:46:43.980121+00 | Select query | SELECT $1;
 00000000000000000000000000000123 | 4268a4281c5316dd | 87cb96b6459880a0 | 2024-03-19 13:46:43.979642+00 | 2024-03-19 13:46:43.979978+00 | Planner      | Planner
 00000000000000000000000000000123 | 4268a4281c5316dd | f5994f9159d8e80d | 2024-03-19 13:46:43.980081+00 | 2024-03-19 13:46:43.980111+00 | Executor     | ExecutorRun

Queries can also be sampled randomly through the pg_tracing.sample_rate parameter. Setting this to 1 will trace all queries.

-- Enable tracing for all queries
SET pg_tracing.sample_rate = 1.0;

-- Execute a query that will be traced
SELECT 1;

-- Check generated spans
select trace_id, parent_id, span_id, span_start, span_end, span_type, span_operation from pg_tracing_consume_spans order by span_start;
             trace_id             |    parent_id     |     span_id      |          span_start           |           span_end            |  span_type   | span_operation
----------------------------------+------------------+------------------+-------------------------------+-------------------------------+--------------+----------------
 458fbefd7034e670eb3d9c930862c378 | eb3d9c930862c378 | bdecb6e35d429f3d | 2024-01-10 09:54:16.321253+00 | 2024-01-10 09:54:16.321587+00 | Select query | SELECT $1;
 458fbefd7034e670eb3d9c930862c378 | bdecb6e35d429f3d | ad49f27543b0175d | 2024-01-10 09:54:16.3213+00   | 2024-01-10 09:54:16.321412+00 | Planner      | Planner
 458fbefd7034e670eb3d9c930862c378 | bdecb6e35d429f3d | 8805f7749249536b | 2024-01-10 09:54:16.321485+00 | 2024-01-10 09:54:16.321529+00 | Executor     | ExecutorRun

Authors

Anthonin Bonnefoy

pg_tracing's People

Contributors

Stargazers

Watchers

Forkers

hlinnaka

pg_tracing's Issues

Assertion failure with cursor

postgres=# create table foo (i int);
CREATE TABLE
postgres=# insert into foo select g from generate_series(1, 100000) g;
INSERT 0 100000
postgres=# set pg_tracing.sample_rate = 1.0;
SET
postgres=# begin;
BEGIN
postgres=*# declare foocur CURSOR FOR SELECT * from foo;
DECLARE CURSOR
postgres=*# fetch forward 10 from foocur;
server closed the connection unexpectedly
	This probably means the server terminated abnormally
	before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.

TRAP: failed Assert("nested_level <= max_nested_level"), File: "src/pg_tracing.c", Line: 620, PID: 510625
postgres: heikki postgres [local] FETCH(ExceptionalCondition+0xaf)[0x55fb74f9651f]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x7242)[0x7f96b5563242]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x4940)[0x7f96b5560940]
postgres: heikki postgres [local] FETCH(ExecutorRun+0x45)[0x55fb74a77db5]
postgres: heikki postgres [local] FETCH(+0x720924)[0x55fb74d76924]
postgres: heikki postgres [local] FETCH(+0x7217ec)[0x55fb74d777ec]
postgres: heikki postgres [local] FETCH(PortalRunFetch+0x179)[0x55fb74d77149]
postgres: heikki postgres [local] FETCH(PerformPortalFetch+0x191)[0x55fb749d7f31]
postgres: heikki postgres [local] FETCH(standard_ProcessUtility+0x515)[0x55fb74d78b25]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x5366)[0x7f96b5561366]
postgres: heikki postgres [local] FETCH(ProcessUtility+0x132)[0x55fb74d785d2]
postgres: heikki postgres [local] FETCH(+0x721c7a)[0x55fb74d77c7a]
postgres: heikki postgres [local] FETCH(+0x720734)[0x55fb74d76734]
postgres: heikki postgres [local] FETCH(PortalRun+0x29f)[0x55fb74d7637f]
postgres: heikki postgres [local] FETCH(+0x71b727)[0x55fb74d71727]
postgres: heikki postgres [local] FETCH(PostgresMain+0x922)[0x55fb74d70992]
postgres: heikki postgres [local] FETCH(+0x713063)[0x55fb74d69063]
postgres: heikki postgres [local] FETCH(postmaster_child_launch+0xe7)[0x55fb74c69867]
postgres: heikki postgres [local] FETCH(+0x61a6fa)[0x55fb74c706fa]
postgres: heikki postgres [local] FETCH(+0x617b99)[0x55fb74c6db99]
postgres: heikki postgres [local] FETCH(PostmasterMain+0x18e7)[0x55fb74c6cd87]
postgres: heikki postgres [local] FETCH(+0x4bd7dd)[0x55fb74b137dd]
/lib/x86_64-linux-gnu/libc.so.6(+0x2724a)[0x7f96b484824a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x85)[0x7f96b4848305]
postgres: heikki postgres [local] FETCH(_start+0x21)[0x55fb74730b21]
2024-05-06 20:44:22.611 EEST [510617] LOG:  server process (PID 510625) was terminated by signal 6: Aborted
2024-05-06 20:44:22.611 EEST [510617] DETAIL:  Failed process was running: fetch forward 10 from foocur;
2024-05-06 20:44:22.611 EEST [510617] LOG:  terminating any other active server processes

Discussion: Supporting OTLP protocol directly

Problem

Currently, you need another program to poll the pg_tracing_consume_spans view and push the spans to an OpenTelemetry Collector. See https://github.com/bonnefoa/pg-tracing-otel-forwarder. I wish the extension could connect directly to the OpenTelemetry Collector, using the OTLP protocol. That would simplify the deployment.

This was discussed on pgsql-hackers: https://www.postgresql.org/message-id/CAO6_Xqr5cNC-fK7kX4Pt9LkYSNjuZQjDfxbm_ckypM9LD8PT1Q%40mail.gmail.com. A pull model made sense for a patch for core PostgreSQL, to avoid having a dependency on HTTP or gRPC or other heavy libraries. But as an extension, that's less of an issue.

Alternatives

One approach is to implement the simplest OTLP/HTTP in JSON protocol using libcurl. Libcurl is widely available and doesn't require a lot of extra baggage.

Another approach would be to add a dependency to the OpenTelemetry C++ client library (https://github.com/open-telemetry/opentelemetry-cpp). That would come with more full support for different transports, but is a much bigger dependency.

Yet another approach would be to bundle a standalone binary like pg-tracing-otel-forwarder with this extensions. The extension could launch it on startup as a separate process, for example. Or just improve the binary to make it nicer to deploy, even though it needs to be deployed separately.

I'm leaning towards the libcurl approach myself. What do you think?

If we go down this route, we could simplify the rest of the code by removing the pull model. It's nice to have something to play with, though, even when you don't have OpenTelemetry colletor or something like Jaeger running. Maybe add an option to dump all the spans to a file instead of pushing them with OTLP?

Only first statement in multi-statement is traced

Steps to reproduce the issue

$ psql postgres -c "select count(*) from pg_am; select count(*) from pg_class"
 count 
-------
     7
(1 row)

 count 
-------
   420
(1 row)

$ psql postgres -c "select trace_id, span_id, span_type, span_operation from pg_tracing_consume_spans"
             trace_id             |     span_id      |  span_type   |       span_operation        
----------------------------------+------------------+--------------+-----------------------------
 266759934ee85fe1100bf7a07bd43421 | 1b40b22bc5da4fa8 | Planner      | Planner
 266759934ee85fe1100bf7a07bd43421 | 88167138ea5945e5 | Executor     | ExecutorRun
 266759934ee85fe1100bf7a07bd43421 | d10fe19e7702ecd0 | SeqScan      | SeqScan on pg_am
 266759934ee85fe1100bf7a07bd43421 | 85e37a824bf3962b | Aggregate    | Aggregate
 266759934ee85fe1100bf7a07bd43421 | 7ffdd4d4338ba069 | Select query | select count(*) from pg_am;
(5 rows)

There are no spans for the second query, select count(*) from pg_class.

Crash on SQL comments on explicit BEGIN

postgres=# /*traceparent='00-00000000000000000000000000000128-0000000000000128-01'*/begin; insert into foo values(1); commit;
BEGIN
server closed the connection unexpectedly
	This probably means the server terminated abnormally
	before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.

TRAP: failed Assert("!traceid_zero(span->trace_id)"), File: "src/pg_tracing_span.c", Line: 127, PID: 556201
postgres: heikki postgres ::1(42026) INSERT(ExceptionalCondition+0xaf)[0x55900b67551f]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0xc978)[0x7f045eeb0978]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x7527)[0x7f045eeab527]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x45f2)[0x7f045eea85f2]
postgres: heikki postgres ::1(42026) INSERT(planner+0x3d)[0x55900b2d09ad]
postgres: heikki postgres ::1(42026) INSERT(pg_plan_query+0x94)[0x55900b44d424]
postgres: heikki postgres ::1(42026) INSERT(pg_plan_queries+0x139)[0x55900b44d5d9]
postgres: heikki postgres ::1(42026) INSERT(+0x71b575)[0x55900b450575]
postgres: heikki postgres ::1(42026) INSERT(PostgresMain+0x922)[0x55900b44f992]
postgres: heikki postgres ::1(42026) INSERT(+0x713063)[0x55900b448063]
postgres: heikki postgres ::1(42026) INSERT(postmaster_child_launch+0xe7)[0x55900b348867]
postgres: heikki postgres ::1(42026) INSERT(+0x61a6fa)[0x55900b34f6fa]
postgres: heikki postgres ::1(42026) INSERT(+0x617b99)[0x55900b34cb99]
postgres: heikki postgres ::1(42026) INSERT(PostmasterMain+0x18e7)[0x55900b34bd87]
postgres: heikki postgres ::1(42026) INSERT(+0x4bd7dd)[0x55900b1f27dd]
/lib/x86_64-linux-gnu/libc.so.6(+0x2724a)[0x7f045e24824a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x85)[0x7f045e248305]
postgres: heikki postgres ::1(42026) INSERT(_start+0x21)[0x55900ae0fb21]
2024-05-07 14:14:26.263 EEST [556193] LOG:  server process (PID 556201) was terminated by signal 6: Aborted
2024-05-07 14:14:26.263 EEST [556193] DETAIL:  Failed process was running: insert into foo values(1);
2024-05-07 14:14:26.263 EEST [556193] LOG:  terminating any other active server processes
2024-05-07 14:14:26.264 EEST [556193] LOG:  all server processes terminated; reinitializing