Re: POC: Extension for adding distributed tracing - pg_tracing - Mailing list pgsql-hackers

From Nikita Malakhov
Subject Re: POC: Extension for adding distributed tracing - pg_tracing
Date
Msg-id CAN-LCVPRfwHMWFTVNbEAtb2R4draw7RDE88QT3hG8+x3xshDqw@mail.gmail.com
Whole thread Raw
In response to Re: POC: Extension for adding distributed tracing - pg_tracing  (Anthonin Bonnefoy <anthonin.bonnefoy@datadoghq.com>)
Responses Re: POC: Extension for adding distributed tracing - pg_tracing
List pgsql-hackers
Hi!

Storing spans is a tricky question. Monitoring systems often use pull model and use probes or SQL
API for pulling data, so from this point of view it is much more convenient to keep spans in separate
table. But in this case we come to another issue - how to flush this data into the table? Automatic
flushing on a full buffer would randomly (to the user) significantly affect query performance. I'd rather
make a GUC turned off by default to store spans into the table instead of buffer.

>3) I'm testing more complex queries. Most of my previous tests were using simple query protocol but extended protocol introduces
>differences that break some assumptions I did. For example, with multi statement transaction like
>BEGIN;
>SELECT 1;
>SELECT 2;
>The parse of SELECT 2 will happen before the ExecutorEnd (and the end_tracing) of SELECT 1. For now, I'm skipping the post parse 
>hook if we still have an ongoing tracing.

I've checked this behavior before and haven't noticed the case you mentioned, but for
loops like
        for i in 1..2 loop
                StartTime := clock_timestamp();
        insert into t2 values (i, a_data);
        EndTime := clock_timestamp();
        Delta := 1000 * ( extract(epoch from EndTime) - extract(epoch from StartTime) );
        end loop;

I've got the following call sequence:
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <1>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <1>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <2>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <2>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <StartTime := clock_timestamp()>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <StartTime := clock_timestamp()>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorStart <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorRun  <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorFinish <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorEnd <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <EndTime := clock_timestamp()>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <EndTime := clock_timestamp()>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_post_parse_analyze hook <Delta := 1000 * ( extract(epoch from EndTime) - extract(epoch from StartTime) )>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <Delta := 1000 * ( extract(epoch from EndTime) - extract(epoch from StartTime) )>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_planner_hook <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorStart <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorRun  <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorFinish <insert into t2 values (i, a_data)>
psql:/home/postgres/tests/trace.sql:52: NOTICE:  pg_tracing_ExecutorEnd <insert into t2 values (i, a_data)>

--
Regards,
Nikita Malakhov
Postgres Professional
The Russian Postgres Company

pgsql-hackers by date:

Previous
From: Andy Fan
Date:
Subject: Re: Extract numeric filed in JSONB more effectively
Next
From: Michael Paquier
Date:
Subject: Re: Support to define custom wait events for extensions