Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.96) (envelope-from ) id 1wLUb5-001obT-0D for pgsql-hackers@arkaria.postgresql.org; Fri, 08 May 2026 23:27:07 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.96) (envelope-from ) id 1wLUb3-00Bjt5-2G for pgsql-hackers@arkaria.postgresql.org; Fri, 08 May 2026 23:27:05 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.96) (envelope-from ) id 1wLUX2-00BRFf-0Y for pgsql-hackers@lists.postgresql.org; Fri, 08 May 2026 23:22:56 +0000 Received: from mail-wm1-x32d.google.com ([2a00:1450:4864:20::32d]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.98.2) (envelope-from ) id 1wLUX0-00000001JTv-0hkv for pgsql-hackers@postgresql.org; Fri, 08 May 2026 23:22:55 +0000 Received: by mail-wm1-x32d.google.com with SMTP id 5b1f17b1804b1-48334ee0aeaso19034225e9.1 for ; Fri, 08 May 2026 16:22:54 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20251104; t=1778282572; x=1778887372; darn=postgresql.org; h=content-transfer-encoding:mime-version:message-id:date:subject:cc :to:from:from:to:cc:subject:date:message-id:reply-to; bh=FDfYK1y5PdUDWpYSluOhjKGaOGFuFe3r3qvppHUtatk=; b=JJLe31SBCzZc08IUvzFeLjAyj6+yA1+wDhRciYbeSZIENNI/kvIy0w1NunZa8B976v pdYEPdor11KeMuk9vPsk/AtI5mcUDtcPweyINVGjfc95q8bs9C2WUAIXUrQRBKNLMOrn J3APFWSXRbsd/xLbA8bEtsCt1QlB4u6DrmrLgNgNhh4zkLHIppRheYPs1ZKrWYbwzBYE Qv6IBFUF+BQfdr7yswGge8QP3m8ca07+/rSa6Vx4GwnRhdS3Bg4IgjYcGy8dvswT1HiI ZaaQGRYzNbHFbRaPkDazj4RRNNtH0u1z+0hXctiRdOizVI2nYFyHJp9V06pIulMmYT/G HjWA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20251104; t=1778282572; x=1778887372; h=content-transfer-encoding:mime-version:message-id:date:subject:cc :to:from:x-gm-gg:x-gm-message-state:from:to:cc:subject:date :message-id:reply-to; bh=FDfYK1y5PdUDWpYSluOhjKGaOGFuFe3r3qvppHUtatk=; b=JjGnCgsZUeVyVv/OQITGyzqbAS2gF+1lZJY0sMlpY3KVMuICi08EnO6yJbdsLnb+gc N/wX9w33+gfUaaHw0GvQpkRR76sOsdf5iWn34CqdruDkxnXNEzlAbNDyyhGOE23XFM1L UOHGbgAWDnZQwZ6VuxIJmvLl+HEpCeKZaUfNFj1661Bih1tSbAdw4lKq2k438PNJmB1J wI519ffKihpO3eMWd7pMBNC0eqq5VRpoHDddBtkXdR8/Ow1BCVVplcO521k6AJbQSKhi SgTKedN4wcIR8xEODRav+K+TUWkD3/wd9ZaNwTsfrJQ5GK96tbiEz1c9SyYEGfRkweAz NOJg== X-Gm-Message-State: AOJu0Yzj3VV71V2sfCp7ttkleU4mUZa0Qaa1aCBPpZ+OgAnUkwBvlgAY RmaTf0vejHKyfkOjcPn41vUEcIeo0y2Qx3XJncaM3hlBdYRIKZmGMNeCvV4N4IjyCxY= X-Gm-Gg: AeBDieuv6WGaTU5Thyo/5Y7f6jgVVldt+KBm+FtmxAXOw27VhVm+i6VCrLrqwRvaUid ahn5Ek61aMEk4dRXbLx5UTGCGpFOlaDJnGMKLIXrp43p7erPEiK1INQf7/W7FhoufAuVfhIZR+m Yf0hiLCJzffhGglRHgLKpoI+MWzrgvfsj3N2KhZUO4Tr0yfibUFg82Aag4sr7k8SCP+EdnMKMIg fHt1m8/V/U+B47xnLccwj/H30mlDgVSRaVTtGTvkoiFzi7ILKx7sIVtXtoc12As0ZHaCLErfMVE vyvURCFzxJpY2KkKq5XfF+oXrJNdu8t0NBlGe+8M04N3I2NZPnHTeWEBM46Ny4m61As6/+LkhSN O3iaSdcAwf93CAoq7H9X2UqGYiFKAkqq6kuQMfaOhPyTVvxpYLEX3TVN9Q7ctu92PCHkMsPU7yP NgYYMLhmimg0Hxm9WK820RoOY1yohzn8CA6xFwE0r2IYLwF4rIIKbViernrosjYc37X6oxNWIq6 +u84CQDgFLMOp1nh85zZCWmUtdokY67yg== X-Received: by 2002:a05:600c:a110:b0:48a:5574:3a5d with SMTP id 5b1f17b1804b1-48e51e195dcmr184549585e9.7.1778282571454; Fri, 08 May 2026 16:22:51 -0700 (PDT) Received: from localhost.localdomain (a195b158c78d62.go.net.mt. [195.158.78.62]) by smtp.gmail.com with ESMTPSA id 5b1f17b1804b1-48e6fffb9bdsm6224775e9.1.2026.05.08.16.22.48 (version=TLS1_3 cipher=TLS_CHACHA20_POLY1305_SHA256 bits=256/256); Fri, 08 May 2026 16:22:50 -0700 (PDT) From: Ilmar Yunusov To: pgsql-hackers@postgresql.org Cc: Ilmar Yunusov Subject: [RFC PATCH v0 0/7] Add EXPLAIN ANALYZE wait event reporting Date: Sat, 9 May 2026 04:22:30 +0500 Message-ID: X-Mailer: git-send-email 2.52.0 MIME-Version: 1.0 Content-Transfer-Encoding: 8bit List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk This RFC prototype adds `EXPLAIN (ANALYZE, WAITS)`, which reports completed wait intervals observed through `pgstat_report_wait_start/end()`. The option is named `WAITS` in this RFC to match the short style of `BUFFERS`, `WAL`, `IO`, and `MEMORY`. I am not attached to the exact name; `WAIT_EVENTS` may be clearer but is more verbose. PostgreSQL already exposes a backend's current wait event through pg_stat_activity. This patch explores making the same wait event instrumentation useful in EXPLAIN ANALYZE by collecting per-statement and per-plan-node wait event usage while a statement executes. Statement-level output is reported as `Statement Wait Events`. It counts each completed wait once per active statement-level collector and includes parallel worker waits. Nested EXPLAIN ANALYZE WAITS collectors maintain separate statement-level summaries; a wait is counted once in each active collector. Plan-node output is reported as `Wait Events`. Node-level attribution is intentionally inclusive, matching EXPLAIN ANALYZE node timing: a wait is attributed to every active plan node captured when the wait begins. This means parent and child nodes can show the same wait, and node-level wait times must not be summed to compute a statement total. The implementation keeps wait-end accounting allocation-free. Each statement and plan-node accumulator preallocates storage for 64 distinct wait event identities; additional distinct identities are accumulated in `Unrecorded Wait Event Calls` and `Unrecorded Wait Event Time` without event identity. The fixed bound is intended to make the wait-end path predictable and safe in places where allocation would be undesirable. The overflow bucket preserves total calls/time, but loses per-event identity. This is a deliberate RFC point. Patch layout: 1. add statement-level EXPLAIN WAITS reporting; 2. aggregate statement-level waits from parallel workers; 3. add plan-node wait attribution, including manual executor paths; 4. refine attribution semantics, docs, overflow output, and tests; 5. harden accumulator handling and keep wait-end allocation-free; 6. hide accumulator internals behind the wait-event accounting API; 7. update EXPLAIN option tab completion. Important review questions: - Is the `WAITS` option name and output shape acceptable, or should this be `WAIT_EVENTS` / different labels? - Is inclusive per-node attribution the right semantic for EXPLAIN? - Is the fixed 64-entry accumulator plus explicit overflow bucket acceptable? - Is the disabled hot-path overhead of checking an exported boolean in pgstat_report_wait_start/end acceptable? - Are the test scaffolding choices acceptable, especially planner GUCs and pg_sleep wrappers used to force deterministic wait-attribution cases? The tests use pg_sleep only to force a stable Timeout:PgSleep wait identity; durations are normalized by the existing EXPLAIN test filters. Local verification so far: - `make -s -j4` - `make -C doc/src/sgml check` - `make -s -C src/bin/psql` - `make -C src/test/regress check-tests TESTS='test_setup create_index explain'` - `git diff --check` The final diff of this 7-patch branch is identical to the development branch `r314tive/pg-wait-explain-mvp`. Local optimized macOS microbenchmarks are directional only. The current synthetic C wait-loop run measured roughly 0.1-0.2 ns/wait disabled overhead and about 30 ns/wait enabled accounting for a single active node. These numbers are not intended as performance evidence for commit; they only served as a local smoke check that the disabled path is plausibly small. I would want repeated Linux, CPU-pinned numbers before drawing stronger conclusions. Ilmar Yunusov (7): Add EXPLAIN WAITS statement reporting Aggregate EXPLAIN WAITS from parallel workers Attribute EXPLAIN WAITS to plan nodes Refine EXPLAIN WAITS attribution semantics Harden EXPLAIN WAITS accumulator handling Hide EXPLAIN WAITS accumulator internals Keep EXPLAIN option completion current doc/src/sgml/ref/explain.sgml | 61 ++++ src/backend/commands/explain.c | 172 +++++++++- src/backend/commands/explain_state.c | 8 + src/backend/executor/execAsync.c | 22 ++ src/backend/executor/execMain.c | 1 + src/backend/executor/execParallel.c | 295 ++++++++++++++++- src/backend/executor/execProcnode.c | 24 +- src/backend/executor/execUtils.c | 1 + src/backend/executor/instrument.c | 7 + src/backend/executor/nodeBitmapAnd.c | 7 + src/backend/executor/nodeBitmapIndexscan.c | 7 + src/backend/executor/nodeBitmapOr.c | 7 + src/backend/executor/nodeHash.c | 7 + src/backend/utils/activity/wait_event.c | 363 +++++++++++++++++++++ src/bin/psql/tab-complete.in.c | 6 +- src/include/commands/explain_state.h | 1 + src/include/executor/execParallel.h | 2 + src/include/executor/instrument.h | 1 + src/include/nodes/execnodes.h | 3 + src/include/utils/wait_event.h | 45 +++ src/test/regress/expected/explain.out | 202 ++++++++++++ src/test/regress/sql/explain.sql | 144 ++++++++ 22 files changed, 1371 insertions(+), 15 deletions(-) -- 2.52.0