public inbox for [email protected]  
help / color / mirror / Atom feed
From: Maksim Gorkov <[email protected]>
To: Michael Paquier <[email protected]>
Cc: [email protected]
Subject: Re: The same query_id for different queries
Date: Tue, 1 Jul 2025 18:08:45 +0300
Message-ID: <CA+mz3HgVY0N9WKVPrQ13t7H3aYSVyEsm56P2caX8Ftbr+ewgNA@mail.gmail.com> (raw)
In-Reply-To: <[email protected]>
References: <CA+mz3HiQYrYvvcbzV+mvXdAsEL31UkV_6RTgfcTdARMoOkEeWQ@mail.gmail.com>
	<[email protected]>

A few more examples:
1. Why are different query_ids displayed in the log for this test query?
2025-07-01 13:38:47.852 MSK [2518006:549/405366] [postgres] pgAdmin
*-11391618518959119* 10.206.112.24(51180) LOG:  duration: 101.141 ms  plan:
        Query Text: BEGIN;
        select pg_sleep(.1);
        COMMIT;

        Result  (cost=0.00..0.01 rows=1 width=4) (actual
time=101.130..101.131 rows=1 loops=1)
2025-07-01 13:38:47.852 MSK [2518006:549/0] [postgres] pgAdmin
*2064869707185898531* 10.206.112.24(51180) LOG:  duration: 101.322 ms
 statement: BEGIN;
        select pg_sleep(.1);
        COMMIT;

2. The first two lines in the log show the query_id equal to 0, but in the
last line the query_id is different and it is the same as in the previous
example:
2025-07-01 00:01:28.625 MSK [1931448:19/12331582] [dbname1] *0* [local]
apname1 LOG:  duration: 55.881 ms  execute <unnamed>:
                        WITH progress AS MATERIALIZED (
                                SELECT
                                    unnest[1]::integer event_id,
                                    unnest[2]::date period_date,
                                    unnest[3]::integer account,
                                    unnest[4]::date planned_date
                                FROM (
                                    SELECT unnest($1::text[])::text[]
                                ) AS F
                        )
                        SELECT *
                        FROM "SummaryState"
                        INNER JOIN progress ON(
                            "Event" = "event_id"
                            AND "PeriodDate" = "period_date"
                            AND "DateTime" = "planned_date"
                            AND "Account" = "account"
                        )
                        WHERE "DateTime" = ANY($2)

2025-07-01 00:01:28.625 MSK [1931448:19/12331582] [dbname1] *0* [local]
apname1 DETAIL:  parameters: $1 = '{ "{ 9714705, ''2024-12-31'', 20751406,
''2025-0>
2025-07-01 00:01:28.627 MSK [1931448:19/12331582] [dbname1]
*2064869707185898531* [local] apname1 LOG:  duration: 55.874 ms  plan:
        Query Text:
                        WITH progress AS MATERIALIZED (
                                SELECT
                                    unnest[1]::integer event_id,
                                    unnest[2]::date period_date,
                                    unnest[3]::integer account,
                                    unnest[4]::date planned_date
                                FROM (
                                    SELECT unnest($1::text[])::text[]
                                ) AS F
                        )
                        SELECT *
                        FROM "SummaryState"
                        INNER JOIN progress ON(
                            "Event" = "event_id"
                            AND "PeriodDate" = "period_date"
                            AND "DateTime" = "planned_date"
                            AND "Account" = "account"
                        )
                        WHERE "DateTime" = ANY($2)

        Query Parameters: $1 = '{ "{ 9714705, ''2024-12-31'', 20751406,
''2025-03-25'' }","{ 9714705, ''2023-12-31'', 20751406, ''2024-03-25''
}","{ 9714706, ''2025-06-30'', 20751406, ''2025-07-25'' }","{ 97147>
        Nested Loop  (cost=4.74..5235.80 rows=13 width=312) (actual
time=1.477..55.146 rows=86 loops=1)
          Buffers: shared hit=303 read=93
          I/O Timings: shared read=51.064
          CTE progress
            ->  Subquery Scan on f  (cost=0.00..4.20 rows=88 width=16)
(actual time=0.080..0.578 rows=88 loops=1)
                  ->  Result  (cost=0.00..2.44 rows=88 width=32) (actual
time=0.053..0.303 rows=88 loops=1)
                        ->  ProjectSet  (cost=0.00..0.46 rows=88 width=32)
(actual time=0.049..0.098 rows=88 loops=1)
                              ->  Result  (cost=0.00..0.01 rows=1 width=0)
(actual time=0.001..0.002 rows=1 loops=1)
          ->  CTE Scan on progress  (cost=0.00..1.76 rows=88 width=16)
(actual time=0.085..0.670 rows=88 loops=1)
          ->  Append  (cost=0.54..59.22 rows=21 width=295) (actual
time=0.613..0.615 rows=1 loops=88)
<skipped>

On Tue, Jul 1, 2025 at 11:16 AM Michael Paquier <[email protected]> wrote:

> On Tue, Jul 01, 2025 at 10:24:14AM +0300, Maksim Gorkov wrote:
> > 2064869707185898531;'BEGIN;...' -- the full text in query1.sql attachment
> > 2064869707185898531;'COMMIT;'
> >
> > there is another example, if required I can send it for review.
> >
> > Why does this happen and how can it be fixed?
>
> Hard to say based on the information you are giving here.  First, what
> you are posting is not a self-contained case.  It sounds to me that
> you may be seeing two entries with one for a top-level query and one
> for a non-top-level query.  In this case the same query ID could be
> used.
> --
> Michael
>


view thread (3+ messages)

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: [email protected]
  Cc: [email protected], [email protected]
  Subject: Re: The same query_id for different queries
  In-Reply-To: <CA+mz3HgVY0N9WKVPrQ13t7H3aYSVyEsm56P2caX8Ftbr+ewgNA@mail.gmail.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox