Add more WAL metrics #3685

ilidemi · 2025-11-12T06:02:25Z

Adding a bunch of WAL metrics in hopes of better seeing the impact of deployment on a busy instance.

pg_stat_activity.wait_event_type/wait_event for our backend: these are really the source of truth on when the wal sender becomes idle (wait_event_type=Client, wait_event= WalSenderWaitForWAL) because there's nothing to send (even if the current lsn is ahead of what was sent to us because of an unfinished transaction). However, it also can change many times a second and polling once every few minutes is pretty sparse. Putting it in in case it's still useful.

Commit LSN on the receiver - the latest we've received from Postgres so far

pg_stat_replication.sent_lsn - we don't always have permission to read this one but saw some discrepancies with commit LSN so keeping as optional for debugging purposes

Current LSN - to diff with commit LSN

Deltas between PG-side LSNs, just for convenience

pg_stat_replication_slots.spill_txns/spill_count/spill_bytes (PG16+), logical_decoding_work_mem (PG13+) - to see what the PG is doing after reconnect and before it sent anything to us, and be able to diagnose bad setting

Misc quality of life metrics:

pg_replication_slots.safe_wal_size (PG13+) - monitor danger zone when we're behind or there's a burst

pg_replication_slots.active/wal_status, pg_stat_activity.state

actually test this

Copilot

Pull Request Overview

This PR adds extensive WAL (Write-Ahead Log) metrics to improve visibility into PostgreSQL replication slot behavior, particularly during reconnection scenarios. The new metrics help identify bottlenecks across different replication phases and provide insights into logical decoding memory usage and disk spilling.

Key changes:

Adds 15+ new metrics tracking LSN positions, deltas between replication phases, and WAL sender state
Introduces monitoring for logical decoding work memory configuration and spill statistics (PG16+)
Enhances slot monitoring with wait event tracking and safe WAL size indicators

Reviewed Changes

Copilot reviewed 8 out of 8 changed files in this pull request and generated 1 comment.

Show a summary per file

File	Description
protos/route.proto	Adds 15 new fields to SlotInfo message for enhanced WAL metrics
nexus/catalog/migrations/V49__enhanced_slot_metrics.sql	Creates database migration to add new metric columns to peer_slot_size table
flow/otel_metrics/otel_manager.go	Defines and initializes new OpenTelemetry gauge metrics for WAL monitoring
flow/otel_metrics/attributes.go	Adds new attribute keys for wait events, backend state, and WAL status
flow/connectors/utils/monitoring/monitoring.go	Updates AppendSlotSizeInfo to persist all new metric fields
flow/connectors/postgres/postgres.go	Records new metrics in HandleSlotInfo and removes nil-check guards
flow/connectors/postgres/client.go	Rewrites getSlotInfo query with JOINs to collect comprehensive slot and replication statistics
flow/activities/flowable.go	Wires new metric gauges into the FlowableActivity's RecordSlotSizes

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

flow/connectors/utils/monitoring/monitoring.go

Co-authored-by: Copilot <[email protected]>

ilidemi · 2025-11-12T06:07:41Z

Q: anything preventing us from querying this every minute instead of 5? 5 is kinda close to the unhappy zone for the customers

codecov · 2025-11-12T06:21:54Z

❌ 2 Tests Failed:

Tests completed	Failed	Passed	Skipped
1288	2	1286	131

View the full list of 2 ❄️ flaky test(s)

github.com/PeerDB-io/peerdb/flow/e2e::TestApiPg

Flake rate in main: 17.89% (Passed 312 times, Failed 68 times)

Stack Traces | 0.01s run time

=== RUN   TestApiPg
=== PAUSE TestApiPg
=== CONT  TestApiPg
--- FAIL: TestApiPg (0.01s)
2025/11/17 00:16:55 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2025/11/17 00:16:55 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}

github.com/PeerDB-io/peerdb/flow/e2e::TestApiPg/TestQRep

Flake rate in main: 14.21% (Passed 326 times, Failed 54 times)

Stack Traces | 63.2s run time

=== RUN   TestApiPg/TestQRep
=== PAUSE TestApiPg/TestQRep
=== CONT  TestApiPg/TestQRep
2025/11/17 00:15:00 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2025/11/17 00:15:00 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2025/11/17 00:15:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id"
2025/11/17 00:15:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id"
2025/11/17 00:15:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_16706529530404978036 CURSOR FOR SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id" args=[]
2025/11/17 00:15:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id" channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_16706529530404978036
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_16706529530404978036 records=4 bytes=48 channelLen=3
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id" rows=4 bytes=48 channelLen=3
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_16706529530404978036
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_16706529530404978036 records=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes\" ORDER BY id" rows=4 bytes=48 channelLen=0
2025/11/17 00:15:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id"
2025/11/17 00:15:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id"
2025/11/17 00:15:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_15356675899324954548 CURSOR FOR SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id" args=[]
2025/11/17 00:15:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id" channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_15356675899324954548
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_15356675899324954548 records=3 bytes=36 channelLen=2
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id" rows=3 bytes=36 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_15356675899324954548
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_15356675899324954548 records=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,c1 FROM e2e_test_pg_uqyrwjhv.\"test_simple_schema_changes_dst\" ORDER BY id" rows=3 bytes=36 channelLen=0
    api_test.go:1239: WaitFor qrep initial load 2025-11-17 00:15:00.38709522 +0000 UTC m=+131.245856835
2025/11/17 00:15:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id"
2025/11/17 00:15:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id"
2025/11/17 00:15:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_10104150020541179310 CURSOR FOR SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" args=[]
2025/11/17 00:15:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10104150020541179310
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10104150020541179310 records=1 bytes=9 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=1 bytes=9 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10104150020541179310
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10104150020541179310 records=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=1 bytes=9 channelLen=0
    api_test.go:1239: code: 60, message: Unknown table expression identifier 'qrepapi_api_i7v7tcj2' in scope SELECT id, val FROM qrepapi_api_i7v7tcj2 FINAL WHERE _peerdb_is_deleted = 0 ORDER BY 1 ASC SETTINGS use_query_cache = false
2025/11/17 00:15:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_12368057687730231359 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2025/11/17 00:15:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12368057687730231359
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12368057687730231359 records=8 bytes=168 channelLen=7
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12368057687730231359
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12368057687730231359 records=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2025/11/17 00:15:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_17721935186335616461 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" args=[]
2025/11/17 00:15:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17721935186335616461
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17721935186335616461 records=3 bytes=63 channelLen=2
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=2
2025/11/17 00:15:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17721935186335616461
2025/11/17 00:15:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17721935186335616461 records=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=0
    api_test.go:1244: WaitFor insert post qrep initial load 2025-11-17 00:15:01.40613528 +0000 UTC m=+132.264896885
2025/11/17 00:15:01 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id"
2025/11/17 00:15:01 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id"
2025/11/17 00:15:01 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_10814477044230201898 CURSOR FOR SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" args=[]
2025/11/17 00:15:01 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10814477044230201898
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10814477044230201898 records=2 bytes=19 channelLen=1
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=2 bytes=19 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10814477044230201898
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10814477044230201898 records=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:01 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_i7v7tcj2.\"qrepapi_api_i7v7tcj2\" ORDER BY id" rows=2 bytes=19 channelLen=0
    api_test.go:1244: q.NumRecords: 2
    api_test.go:1244: other.NumRecords: 1
2025/11/17 00:15:01 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:01 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:01 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_12957010335837172849 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2025/11/17 00:15:01 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12957010335837172849
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12957010335837172849 records=8 bytes=168 channelLen=7
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=7
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12957010335837172849
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12957010335837172849 records=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:01 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2025/11/17 00:15:01 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:01 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:01 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_3763614576510736419 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" args=[]
2025/11/17 00:15:01 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3763614576510736419
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3763614576510736419 records=3 bytes=63 channelLen=2
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=2
2025/11/17 00:15:01 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3763614576510736419
2025/11/17 00:15:01 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3763614576510736419 records=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:01 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:01 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=0
    api_test.go:1244: q.NumRecords: 2
    api_test.go:1244: other.NumRecords: 1
2025/11/17 00:15:02 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2025/11/17 00:15:02 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:02 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:02 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_15390011349517442824 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2025/11/17 00:15:02 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2025/11/17 00:15:02 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
    api_test.go:1256: WaitFor finish 2025-11-17 00:15:03.433434202 +0000 UTC m=+134.292195817
2025/11/17 00:15:03 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:03 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id"
2025/11/17 00:15:03 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_13067060322559198188 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2025/11/17 00:15:03 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13067060322559198188
2025/11/17 00:15:03 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13067060322559198188 records=8 bytes=168 channelLen=7
2025/11/17 00:15:03 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13067060322559198188
2025/11/17 00:15:03 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13067060322559198188 records=0 bytes=0 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:03 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2025/11/17 00:15:03 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:03 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id"
2025/11/17 00:15:03 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_4602859401494687939 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" args=[]
2025/11/17 00:15:03 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_4602859401494687939
2025/11/17 00:15:03 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_4602859401494687939 records=3 bytes=63 channelLen=2
2025/11/17 00:15:03 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_4602859401494687939
2025/11/17 00:15:03 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_4602859401494687939 records=0 bytes=0 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=0 bytes=0 channelLen=0
2025/11/17 00:15:03 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2025/11/17 00:15:03 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pg_dfovejkt.\"test_inheritance_dynconf_dst\" ORDER BY id" rows=3 bytes=63 channelLen=0
    api_test.go:1256: UNEXPECTED TIMEOUT finish 2025-11-17 00:16:03.558833576 +0000 UTC m=+194.417595191
    api_test.go:44: begin tearing down postgres schema api_i7v7tcj2
--- FAIL: TestApiPg/TestQRep (63.24s)

To view more test analytics, go to the Test Analytics Dashboard
_{📋 Got 3 mins? Take this short survey to help us improve Test Analytics.}

nexus/catalog/migrations/V49__enhanced_slot_metrics.sql

flow/connectors/postgres/client.go

flow/connectors/postgres/postgres.go

Add more WAL metrics

c29f7f9

ilidemi requested a review from Copilot November 12, 2025 06:02

Copilot AI reviewed Nov 12, 2025

View reviewed changes

flow/connectors/utils/monitoring/monitoring.go Outdated Show resolved Hide resolved

Update flow/connectors/utils/monitoring/monitoring.go

9253068

Co-authored-by: Copilot <[email protected]>

iamKunalGupta reviewed Nov 13, 2025

View reviewed changes

nexus/catalog/migrations/V49__enhanced_slot_metrics.sql Outdated Show resolved Hide resolved

ilidemi added 3 commits November 16, 2025 00:59

Don't insert into catalog

e7c981c

Merge branch 'main' into more-wal-metrics

9a4fb96

Add a metric for received commit lsn

152765a

ilidemi marked this pull request as ready for review November 16, 2025 11:56

ilidemi requested a review from jgao54 November 16, 2025 11:57

Remove redundant units

6ea87da

Amogh-Bharadwaj requested a review from heavycrystal November 17, 2025 09:25

Amogh-Bharadwaj approved these changes Nov 17, 2025

View reviewed changes

heavycrystal reviewed Nov 17, 2025

View reviewed changes

flow/connectors/postgres/client.go Outdated Show resolved Hide resolved

flow/connectors/postgres/client.go Show resolved Hide resolved

flow/connectors/postgres/postgres.go Outdated Show resolved Hide resolved

ilidemi added 2 commits November 17, 2025 09:51

Remove pending_restart, make sent_lsn and spill stats optional

0e9be59

update comment

4f26931

ilidemi merged commit 4b2eff7 into main Nov 17, 2025
21 checks passed

ilidemi deleted the more-wal-metrics branch November 17, 2025 18:25

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Add more WAL metrics #3685

Add more WAL metrics #3685

Uh oh!

ilidemi commented Nov 12, 2025 •

edited

Loading

Uh oh!

Copilot AI left a comment

Uh oh!

Uh oh!

ilidemi commented Nov 12, 2025

Uh oh!

codecov bot commented Nov 12, 2025 •

edited

Loading

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Add more WAL metrics #3685

Add more WAL metrics #3685

Uh oh!

Conversation

ilidemi commented Nov 12, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull Request Overview

Reviewed Changes

Uh oh!

Uh oh!

ilidemi commented Nov 12, 2025

Uh oh!

codecov bot commented Nov 12, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

❌ 2 Tests Failed:

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

ilidemi commented Nov 12, 2025 •

edited

Loading

codecov bot commented Nov 12, 2025 •

edited

Loading