Summary:
=== Backport Notes ===
- In `explain.c`
- D45406 / a16d78559d5500127ea1703b34c1a58501cb942e added the Read Ops metric to EXPLAIN. This has not been backported to 2025.1 and is not printed as part of commit stats in 2025.1
- Test outputs:
- Adjusted test outputs to match absence of Read Ops metric.
### Problem
The EXPLAIN command collects stats associated with the current statement during the planning (limited collection) and execution (extensive collection) of the statement.
Notably, EXPLAIN does NOT collect stats associated with committing the statement. Commit stats include those related to execution of deferred constraints (such as foreign keys) and the time taken to perform the commit.
The decision to exclude such stats makes sense for vanilla postgres for a few reasons:
- EXPLAIN collects stats during the lifetime of a statement, while the enclosing transaction is started and committed outside this lifetime.
- The commit itself is not expected to incur significant latency or have errors.
However, in case of YugabyteDB, commits for distributed transactions incur a raft replication, which can be a significant source of latency in multi-region workloads.
Deferred constraints (like in postgres) and writes flushed at commit can similarly be sources of unexplained latency.
This revision introduces a mechanism to collect and display of commit stats with EXPLAIN.
### Solution
The commit stats are collected and stored in a session-level global variable, similar to all the other stats tracked by EXPLAIN.
There are a couple of limitations related to how EXPLAIN constructs and stores its output:
- The string printed by EXPLAIN is finalized and transferred to the output buffer before commit. Once the statement is successfully committed, the output buffer is flushed. This model makes it hard to plug in the commit stats into the same string object after commit. To overcome this limitation, this revision constructs a new EXPLAIN string (that honors the output format) for the commit stats.
- The string tuple (as everything in the output is technically a tuple) containing the EXPLAIN output can be constructed only when a transaction is in progress. This is a generic requirement (not specific to EXPLAIN) arising from the fact that to construct the tuple descriptor, the type information for each of the columns need to be looked up from the catalog cache, and this action requires an active transaction. This revision works around this requirement by starting a dummy transaction soon after the statement's transaction is committed. Within the context of this transaction, the statement's transaction commit stats are flushed to the client. The dummy transaction is subsequently committed. This approach also simplifies the memory management associated with storing the EXPLAIN string.
### Interface
This revision introduces a new EXPLAIN option (`COMMIT`) which allows toggling both the collection and display of commit stats with EXPLAIN statements.
When the option is not set explicitly, commit stats are not collected or displayed.
### Other Tools
This section describes whether commonly used observability tools collect and display commit stats:
| **Tool** | **Includes commit latency?** | **Description** |
| EXPLAIN | Yes | Collection of commit is introduced with this commit |
| PG statement logging | Yes | Statements are timed post-commit using `current timestamp - statement start timestamp` |
| pg_stat_statements | No | Pgss plugs into statement hooks, so do not contain stats from outside its lifetime |
| pg_audit | No | pg_audit does not display execution time stats |
### Sample Output
```
yugabyte=# EXPLAIN (ANALYZE, DIST, COMMIT, COSTS OFF) INSERT INTO t_test VALUES (3, 3, 3);
QUERY PLAN
-----------------------------------------------------------------
Insert on t_test (actual time=14.327..14.361 rows=0 loops=1)
-> Result *RESULT* (actual time=0.002..0.002 rows=1 loops=1)
Storage Table Write Requests: 1
Planning Time: 5.807 ms
Trigger for constraint t_test_p1_fk_fkey: time=8.320 calls=1
Execution Time: 27.379 ms
Storage Read Requests: 1
Storage Read Execution Time: 7.092 ms
Storage Read Ops: 1
Storage Rows Scanned: 1
Catalog Read Requests: 1
Catalog Read Execution Time: 3.304 ms
Catalog Read Ops: 1
Catalog Write Requests: 0
Storage Write Requests: 1
Storage Flush Requests: 0
Storage Execution Time: 10.396 ms
Peak Memory Usage: 211 kB
(18 rows)
COMMIT STATS
---------------------------------------
Storage Read Requests: 1
Storage Read Execution Time: 2.177 ms
Storage Read Ops: 1
Commit Execution Time: 3.868 ms
(4 rows)
```
### Behavior
The commit stats honor all of the current EXPLAIN options:
- When ANALYZE is not enabled, the query is not executed. So commit stats are not collected/displayed.
- When DIST is enabled, RPC stats are collected.
- When timing is turned off, latency related stats are not displayed.
- `yb_explain_hide_non_deterministic_fields` is honored.
=== Limitations ===
- Commit stats are currently only supported for the simple query protocol. Support for the extended query protocol is future work ([#28409](https://github.com/yugabyte/yugabyte-db/issues/28409))
- The framework only collects and display the commit latency and DIST RPCs (count & latency). Support for other stats is future work ([#28410](https://github.com/yugabyte/yugabyte-db/issues/28410))
- Commit stats are not collected for single shard transaction currently. This is future work ([#26963](https://github.com/yugabyte/yugabyte-db/issues/26963)).
Jira: DB-16419
Original commit: a6a98929d7433b33fb6ecd70d426d9523bbd2630 / D45521
Test Plan:
Run the following test:
```
./yb_build.sh --java-test 'org.yb.pgsql.TestPgRegressMisc#testPgRegressMiscSerial5'
./yb_build.sh --java-test 'org.yb.pgsql.TestPgRegressForeignKey'
```
Reviewers: aagrawal, fizaa
Reviewed By: aagrawal
Subscribers: yql, smishra
Tags: #jenkins-ready
Differential Revision: https://phorge.dev.yugabyte.com/D46881