Re: The same query_id for different queries
| От | Maksim Gorkov |
|---|---|
| Тема | Re: The same query_id for different queries |
| Дата | |
| Msg-id | CA+mz3HgVY0N9WKVPrQ13t7H3aYSVyEsm56P2caX8Ftbr+ewgNA@mail.gmail.com обсуждение исходный текст |
| Список | pgsql-general |
A few more examples:
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)
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;
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 <michael@paquier.xyz> 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
В списке pgsql-general по дате отправления: