Fix MySQL CDC hang when SSH tunnel dies by ilidemi · Pull Request #4067 · PeerDB-io/peerdb

ilidemi · 2026-03-18T01:53:12Z

When SSH connection dies during CDC, the keepalive machinery notices but BinlogSyncer is not aware. To make it aware, close SSH connection besides just the MySQL query connection. Add tests for hangs in mystream.GetEvent() and syncer.Close() (both observed in production). Verified that without the fix both tests fail.

codecov · 2026-03-18T02:31:23Z

❌ 2 Tests Failed:

Tests completed	Failed	Passed	Skipped
2201	2	2199	202

View the top 3 failed test(s) by shortest run time

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

Stack Traces | 0.01s run time

=== RUN   TestApiPg
=== PAUSE TestApiPg
=== CONT  TestApiPg
--- FAIL: TestApiPg (0.01s)
2026/04/15 05:30:18 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 05:30:18 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 05:30:18 INFO fetched schema x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} table=e2e_test_mychcl_acybcdbx.test_nullengine

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

Stack Traces | 7.22s run time

=== RUN   TestApiPg/TestDoubleClickCancelTableAddition
=== PAUSE TestApiPg/TestDoubleClickCancelTableAddition
=== CONT  TestApiPg/TestDoubleClickCancelTableAddition
2026/04/15 05:13:27 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 05:13:27 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 05:13:27 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_gnyctilf.\"status_test\" ORDER BY id"
2026/04/15 05:13:27 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_gnyctilf.\"status_test\" ORDER BY id"
2026/04/15 05:13:27 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_13505577483592159370 CURSOR FOR SELECT id,val FROM e2e_test_api_gnyctilf.\"status_test\" ORDER BY id" args=[]
2026/04/15 05:13:27 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_gnyctilf.\"status_test\" ORDER BY id" channelLen=0
2026/04/15 05:13:27 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13505577483592159370
2026/04/15 05:13:27 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13505577483592159370 records=1 bytes=9 channelLen=0
2026/04/15 05:13:27 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_gnyctilf.\"status_test\" ORDER BY id" rows=1 bytes=9 channelLen=0
2026/04/15 05:13:27 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13505577483592159370
2026/04/15 05:13:27 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13505577483592159370 records=0 bytes=0 channelLen=0
2026/04/15 05:13:27 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_gnyctilf.\"status_test\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:13:27 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:13:27 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_gnyctilf.\"status_test\" ORDER BY id" rows=1 bytes=9 channelLen=0
    cancel_table_addition_test.go:1368: WaitFor wait for initial load to finish 2026-04-15 05:13:32.026520923 +0000 UTC m=+648.378478494
2026/04/15 05:13:32 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_f172oqrx.\"t1\" ORDER BY id"
2026/04/15 05:13:32 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_f172oqrx.\"t1\" ORDER BY id"
2026/04/15 05:13:32 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_9281946710710861407 CURSOR FOR SELECT id,val FROM e2e_test_api_f172oqrx.\"t1\" ORDER BY id" args=[]
2026/04/15 05:13:32 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_f172oqrx.\"t1\" ORDER BY id" channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_9281946710710861407
2026/04/15 05:13:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_9281946710710861407 records=1 bytes=9 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_f172oqrx.\"t1\" ORDER BY id" rows=1 bytes=9 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_9281946710710861407
2026/04/15 05:13:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_9281946710710861407 records=0 bytes=0 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_f172oqrx.\"t1\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:13:32 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_f172oqrx.\"t1\" ORDER BY id" rows=1 bytes=9 channelLen=0
    cancel_table_addition_test.go:1379: WaitFor wait for pause 2026-04-15 05:13:32.046302179 +0000 UTC m=+648.398259750
2026/04/15 05:13:32 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id"
2026/04/15 05:13:32 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id"
2026/04/15 05:13:32 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_11783922799475411940 CURSOR FOR SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" args=[]
2026/04/15 05:13:32 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_mzyifluh.\"table1\" ORDER BY id" channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_11783922799475411940
2026/04/15 05:13:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_11783922799475411940 records=2 bytes=19 channelLen=1
2026/04/15 05:13:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" rows=2 bytes=19 channelLen=1
2026/04/15 05:13:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_11783922799475411940
2026/04/15 05:13:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_11783922799475411940 records=0 bytes=0 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:13:32 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:13:32 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_mzyifluh.\"table1\" ORDER BY id" rows=2 bytes=19 channelLen=0
    cancel_table_addition_test.go:1433: WaitFor wait for snapshot status 2026-04-15 05:13:34.069503857 +0000 UTC m=+650.421461428
2026/04/15 05:13:34 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id"
2026/04/15 05:13:34 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id"
2026/04/15 05:13:34 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_12553240109738711939 CURSOR FOR SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" args=[]
2026/04/15 05:13:34 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_mzyifluh.\"table1\" ORDER BY id" channelLen=0
2026/04/15 05:13:34 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12553240109738711939
2026/04/15 05:13:34 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12553240109738711939 records=2 bytes=19 channelLen=1
2026/04/15 05:13:34 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" rows=2 bytes=19 channelLen=1
2026/04/15 05:13:34 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12553240109738711939
2026/04/15 05:13:34 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12553240109738711939 records=0 bytes=0 channelLen=0
2026/04/15 05:13:34 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_mzyifluh.\"table1\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:13:34 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:13:34 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_mzyifluh.\"table1\" ORDER BY id" rows=2 bytes=19 channelLen=0
    cancel_table_addition_test.go:1434: UNEXPECTED ERROR unable to establish connection with catalog: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)
    cancel_table_addition_test.go:1310: begin tearing down postgres schema double_cancel_api_f172oqrx
    api_test.go:48: begin tearing down postgres schema api_f172oqrx
--- FAIL: TestApiPg/TestDoubleClickCancelTableAddition (7.22s)

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

Stack Traces | 24.2s run time

=== RUN   TestApiPg/TestCancelTableAdditionRemoveAddRemove
=== PAUSE TestApiPg/TestCancelTableAdditionRemoveAddRemove
=== CONT  TestApiPg/TestCancelTableAdditionRemoveAddRemove
2026/04/15 04:43:00 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 04:43:00 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id"
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id"
2026/04/15 04:43:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_17898745623484676073 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2026/04/15 04:43:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17898745623484676073
2026/04/15 04:43:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17898745623484676073 records=8 bytes=168 channelLen=7
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=7
2026/04/15 04:43:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17898745623484676073
2026/04/15 04:43:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17898745623484676073 records=0 bytes=0 channelLen=0
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43: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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
2026/04/15 04:43:00 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id"
2026/04/15 04:43:00 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id"
2026/04/15 04:43:00 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_17965996068650993242 CURSOR FOR SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id" args=[]
2026/04/15 04:43:00 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id" channelLen=0
2026/04/15 04:43:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17965996068650993242
2026/04/15 04:43:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17965996068650993242 records=11 bytes=195 channelLen=10
2026/04/15 04:43:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id" rows=11 bytes=195 channelLen=10
2026/04/15 04:43:00 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17965996068650993242
2026/04/15 04:43:00 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_17965996068650993242 records=0 bytes=0 channelLen=0
2026/04/15 04:43:00 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:00 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:00 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,key,value,created_at,extra FROM e2e_test_pgchg_10owm8ou.\"test_partition_reorder\" ORDER BY id" rows=11 bytes=195 channelLen=0
    cancel_table_addition_test.go:637: WaitFor wait for initial load to finish 2026-04-15 04:43:06.617260083 +0000 UTC m=+63.622271776
    cancel_table_addition_test.go:641: WaitFor t1 2026-04-15 04:43:06.617650352 +0000 UTC m=+63.622662046
2026/04/15 04:43:06 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t1\" ORDER BY id"
2026/04/15 04:43:06 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t1\" ORDER BY id"
2026/04/15 04:43:06 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_12653979747615255224 CURSOR FOR SELECT id,val FROM e2e_test_api_vbcudxhj.\"t1\" ORDER BY id" args=[]
2026/04/15 04:43:06 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_vbcudxhj.\"t1\" ORDER BY id" channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12653979747615255224
2026/04/15 04:43:06 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12653979747615255224 records=1 bytes=9 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t1\" ORDER BY id" rows=1 bytes=9 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12653979747615255224
2026/04/15 04:43:06 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_12653979747615255224 records=0 bytes=0 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t1\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:06 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_vbcudxhj.\"t1\" ORDER BY id" rows=1 bytes=9 channelLen=0
    cancel_table_addition_test.go:642: WaitFor t2 2026-04-15 04:43:06.629021851 +0000 UTC m=+63.634033545
2026/04/15 04:43:06 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t2\" ORDER BY id"
2026/04/15 04:43:06 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t2\" ORDER BY id"
2026/04/15 04:43:06 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_3226323452682277019 CURSOR FOR SELECT id,val FROM e2e_test_api_vbcudxhj.\"t2\" ORDER BY id" args=[]
2026/04/15 04:43:06 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_vbcudxhj.\"t2\" ORDER BY id" channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3226323452682277019
2026/04/15 04:43:06 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3226323452682277019 records=1 bytes=9 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t2\" ORDER BY id" rows=1 bytes=9 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3226323452682277019
2026/04/15 04:43:06 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_3226323452682277019 records=0 bytes=0 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_vbcudxhj.\"t2\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:06 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:06 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_vbcudxhj.\"t2\" ORDER BY id" rows=1 bytes=9 channelLen=0
    cancel_table_addition_test.go:82: WaitFor wait for pause for remove e2e_test_api_vbcudxhj.t2 2026-04-15 04:43:06.6372637 +0000 UTC m=+63.642275394
2026/04/15 04:43:06 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id"
2026/04/15 04:43:06 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id"
2026/04/15 04:43:07 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_13895384077997264239 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" args=[]
2026/04/15 04:43:07 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" channelLen=0
2026/04/15 04:43:07 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13895384077997264239
2026/04/15 04:43:07 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13895384077997264239 records=13 bytes=293 channelLen=12
2026/04/15 04:43:07 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=13 bytes=293 channelLen=12
2026/04/15 04:43:07 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13895384077997264239
2026/04/15 04:43:07 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_13895384077997264239 records=0 bytes=0 channelLen=0
2026/04/15 04:43:07 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:07 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:07 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=13 bytes=293 channelLen=0
    cancel_table_addition_test.go:100: WaitFor wait for table removal of source_table_identifier:"e2e_test_api_vbcudxhj.t2"  destination_table_identifier:"t2" to finish 2026-04-15 04:43:08.644339178 +0000 UTC m=+65.649350872
2026/04/15 04:43:09 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id"
2026/04/15 04:43:09 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id"
2026/04/15 04:43:09 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_14518929139452474091 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" args=[]
2026/04/15 04:43:09 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" channelLen=0
2026/04/15 04:43:09 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_14518929139452474091
2026/04/15 04:43:09 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_14518929139452474091 records=13 bytes=293 channelLen=12
2026/04/15 04:43:09 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=13 bytes=293 channelLen=12
2026/04/15 04:43:09 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_14518929139452474091
2026/04/15 04:43:09 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_14518929139452474091 records=0 bytes=0 channelLen=0
2026/04/15 04:43:09 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:09 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:09 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_pgchg_zbf0mxkn.\"test_partition_noroot\" ORDER BY id" rows=13 bytes=293 channelLen=0
    cancel_table_addition_test.go:127: WaitFor wait for pause for add e2e_test_api_vbcudxhj.t2 2026-04-15 04:43:09.650486373 +0000 UTC m=+66.655498067
2026/04/15 04:43:09 INFO queued schema delta update x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} flowName=test_cancel_error_on_pg_zero_oids_api_mdjmeb4m tableName=t1
    cancel_table_addition_test.go:128: UNEXPECTED ERROR unable to establish connection with catalog: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)
    api_test.go:48: begin tearing down postgres schema api_vbcudxhj
2026/04/15 04:43:18 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,name,created_at FROM e2e_test_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id"
2026/04/15 04:43:18 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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id"
2026/04/15 04:43:18 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_7108006854694374696 CURSOR FOR SELECT id,name,created_at FROM e2e_test_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" args=[]
2026/04/15 04:43:18 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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" channelLen=0
2026/04/15 04:43:18 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_7108006854694374696
2026/04/15 04:43:18 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_7108006854694374696 records=8 bytes=168 channelLen=7
2026/04/15 04:43:18 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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=7
2026/04/15 04:43:18 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_7108006854694374696
2026/04/15 04:43:18 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_7108006854694374696 records=0 bytes=0 channelLen=0
2026/04/15 04:43:18 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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 04:43:18 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 04:43:18 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_pgchg_0n28enuy.\"test_inheritance_dynconf\" ORDER BY id" rows=8 bytes=168 channelLen=0
--- FAIL: TestApiPg/TestCancelTableAdditionRemoveAddRemove (24.19s)

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

Stack Traces | 63.3s run time

=== RUN   TestApiPg/TestQRep
=== PAUSE TestApiPg/TestQRep
=== CONT  TestApiPg/TestQRep
2026/04/15 05:28:28 ERROR Failed to get catalog connection pool x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} error="unable to establish connection with catalog: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"
2026/04/15 05:28:28 ERROR Failed to parse bool x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} key=PEERDB_APPLICATION_NAME_PER_MIRROR_NAME error="failed to get catalog connection pool: unable to establish connection with catalog: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"
2026/04/15 05:28:28 ERROR Failed to get flow name from application name x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} error="failed to parse PEERDB_APPLICATION_NAME_PER_MIRROR_NAME as bool: failed to get catalog connection pool: unable to establish connection with catalog: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"
2026/04/15 05:28:28 INFO Received AWS credentials from peer for connector: ci x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
2026/04/15 05:28:28 INFO Received AWS credentials from peer for connector: clickhouse x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN}
    api_test.go:2155: WaitFor qrep initial load 2026-04-15 05:28:28.67574547 +0000 UTC m=+466.845875113
2026/04/15 05:28:28 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id"
2026/04/15 05:28:28 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id"
2026/04/15 05:28:28 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_10487116848847890044 CURSOR FOR SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" args=[]
2026/04/15 05:28:28 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_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" channelLen=0
2026/04/15 05:28:28 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10487116848847890044
2026/04/15 05:28:28 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10487116848847890044 records=1 bytes=9 channelLen=0
2026/04/15 05:28:28 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=1 bytes=9 channelLen=0
2026/04/15 05:28:28 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10487116848847890044
2026/04/15 05:28:28 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10487116848847890044 records=0 bytes=0 channelLen=0
2026/04/15 05:28:28 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:28:28 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:28:28 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_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=1 bytes=9 channelLen=0
    api_test.go:2155: q.NumRecords: 1
    api_test.go:2155: other.NumRecords: 0
    api_test.go:2160: WaitFor insert post qrep initial load 2026-04-15 05:28:29.696578189 +0000 UTC m=+467.866707832
2026/04/15 05:28:29 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id"
2026/04/15 05:28:29 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id"
2026/04/15 05:28:29 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_8549906725005653647 CURSOR FOR SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" args=[]
2026/04/15 05:28:29 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_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" channelLen=0
2026/04/15 05:28:29 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8549906725005653647
2026/04/15 05:28:29 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8549906725005653647 records=2 bytes=19 channelLen=1
2026/04/15 05:28:29 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=2 bytes=19 channelLen=1
2026/04/15 05:28:29 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8549906725005653647
2026/04/15 05:28:29 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8549906725005653647 records=0 bytes=0 channelLen=0
2026/04/15 05:28:29 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,val FROM e2e_test_api_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:28:29 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:28:29 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_xoshqhqv.\"qrepapi_api_xoshqhqv\" ORDER BY id" rows=2 bytes=19 channelLen=0
    api_test.go:2160: q.NumRecords: 2
    api_test.go:2160: other.NumRecords: 1
2026/04/15 05:28:30 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:30 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:30 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_18079940840446288248 CURSOR FOR SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" args=[]
2026/04/15 05:28:30 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" channelLen=0
2026/04/15 05:28:30 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_18079940840446288248
2026/04/15 05:28:30 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_18079940840446288248 records=3 bytes=26 channelLen=2
2026/04/15 05:28:30 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=2
2026/04/15 05:28:30 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_18079940840446288248
2026/04/15 05:28:30 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_18079940840446288248 records=0 bytes=0 channelLen=0
2026/04/15 05:28:30 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:28:30 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:28:30 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=0
    api_test.go:2160: q.NumRecords: 2
    api_test.go:2160: other.NumRecords: 1
2026/04/15 05:28:31 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:31 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:31 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_10705625463778821892 CURSOR FOR SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" args=[]
2026/04/15 05:28:31 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" channelLen=0
2026/04/15 05:28:31 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10705625463778821892
2026/04/15 05:28:31 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10705625463778821892 records=3 bytes=26 channelLen=2
2026/04/15 05:28:31 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=2
2026/04/15 05:28:31 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10705625463778821892
2026/04/15 05:28:31 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_10705625463778821892 records=0 bytes=0 channelLen=0
2026/04/15 05:28:31 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:28:31 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:28:31 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=0
    api_test.go:2179: WaitFor finish 2026-04-15 05:28:31.719688669 +0000 UTC m=+469.889818302
2026/04/15 05:28:32 INFO Executing and processing query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:32 INFO Executing and processing query stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id"
2026/04/15 05:28:32 INFO [pg_query_executor] declared cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursorQuery="DECLARE peerdb_cursor_8850716316024745832 CURSOR FOR SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" args=[]
2026/04/15 05:28:32 INFO [pg_query_executor] fetching rows start x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" channelLen=0
2026/04/15 05:28:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8850716316024745832
2026/04/15 05:28:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8850716316024745832 records=3 bytes=26 channelLen=2
2026/04/15 05:28:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=2
2026/04/15 05:28:32 INFO [pg_query_executor] fetching from cursor x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8850716316024745832
2026/04/15 05:28:32 INFO processed row stream x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart cursor=peerdb_cursor_8850716316024745832 records=0 bytes=0 channelLen=0
2026/04/15 05:28:32 INFO [pg_query_executor] fetched rows x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=0 bytes=0 channelLen=0
2026/04/15 05:28:32 INFO [pg_query_executor] committing transaction x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart
2026/04/15 05:28:32 INFO [pg_query_executor] committed transaction for query x-peerdb-additional-metadata={Operation:FLOW_OPERATION_UNKNOWN} partitionId=testpart query="SELECT id,\"key\" FROM e2e_test_pgch_xxyo3dxh.\"test_nullengine\" ORDER BY id" rows=3 bytes=26 channelLen=0
    api_test.go:2179: UNEXPECTED TIMEOUT finish 2026-04-15 05:29:31.848825918 +0000 UTC m=+530.018955561
    api_test.go:48: begin tearing down postgres schema api_xoshqhqv
--- FAIL: TestApiPg/TestQRep (63.32s)

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

github-actions · 2026-03-18T02:32:42Z

🔄 Flaky Test Detected

Analysis: The test failed due to "context deadline exceeded" when connecting to the Temporal server — a transient infrastructure/network timeout, not a code logic failure.
Confidence: 0.95

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-03-18T02:50:43Z

🔄 Flaky Test Detected

Analysis: Multiple Snowflake e2e tests failed with "UNEXPECTED STATUS TIMEOUT STATUS_SETUP", indicating transient connectivity/availability issues with the external Snowflake service during flow initialization, unrelated to the partitioned table column-ordering code change.
Confidence: 0.92

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-03-19T05:39:03Z

🔄 Flaky Test Detected

Analysis: The e2e test TestGenericBQ/Test_Inheritance_Table_With_Dynamic_Setting timed out during the STATUS_SNAPSHOT phase, which is a classic flaky failure caused by timing-sensitive infrastructure (Temporal/snapshot workflow) rather than a code regression.
Confidence: 0.92

✅ Automatically retrying the workflow

View workflow run

ilidemi · 2026-03-25T19:47:34Z

Current status:

The issue we were looking at in production doesn't seem to be SSH issue
The tests show that it should be an additive improvement reliability wise
There was some weirdness in logs with keepalive errors completely disappearing that we'd need another repro to witness this code working, so will keep as draft until then

ilidemi · 2026-04-10T03:17:45Z

Double checked logs in a local e2e test, looks as expected. Should be good to go

github-actions · 2026-04-10T03:37:23Z

🔄 Flaky Test Detected

Analysis: The e2e test suite hit the 900-second timeout deadline (FAIL github.com/PeerDB-io/peerdb/flow/e2e 900.680s), indicating a flaky timeout rather than a deterministic test assertion failure.
Confidence: 0.9

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-04-14T00:27:03Z

🔄 Flaky Test Detected

Analysis: All three failures are timing/resource-related (setup timeouts, teardown failures, wait-for-load timeouts) with no logic assertion errors, occurring across unrelated matrix jobs on the same commit — classic CI flakiness.
Confidence: 0.9

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-04-14T00:45:33Z

🔄 Flaky Test Detected

Analysis: The test e2e TestApiPg/TestResyncCompleted failed due to a transient PostgreSQL connection drop (SQLSTATE 57P01: admin_shutdown — catalog connection terminated by administrator command), which is an infrastructure/environment issue unrelated to the test logic.
Confidence: 0.95

✅ Automatically retrying the workflow

View workflow run

jgao54 · 2026-04-15T01:51:06Z

+	// the keepalive fires, something else closed the connection (driver timeout, etc.)
+	select {
+	case <-keepaliveChan:
+		t.Log("SSH keepalive detected failure")


It looks like the prod keeepaliveInterval is set to 15s, is my understanding correct that this would take that much time to detect failure? if so, it may be worth setting a shorter interval for test.

I noticed that with the introduction of these two tests, mysql tests now takes 120s (was 60s previously)

Added t.Parallel() which brought it to 30. Overriding the keepalive interval got hairier than I'd prefer with the current code structure, and 30 is in line with other suites.

github-actions · 2026-04-15T04:58:52Z

🔄 Flaky Test Detected

Analysis: TestCancelTableAdditionRemoveAddRemove failed due to a catalog connection being terminated (SQLSTATE 57P01/admin_shutdown), likely caused by the concurrently-running TestCancelErrorOnPgZeroOids test calling pg_terminate_backend() as part of its error-scenario testing while both tests share the same PostgreSQL catalog under -p 32 parallelism.
Confidence: 0.88

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-04-15T05:16:36Z

🔄 Flaky Test Detected

Analysis: TestApiPg/TestDoubleClickCancelTableAddition failed due to a PostgreSQL catalog connection being terminated by an admin command (SQLSTATE 57P01) mid-test — a transient infrastructure event, not a code bug.
Confidence: 0.93

✅ Automatically retrying the workflow

View workflow run

github-actions · 2026-04-15T05:34:52Z

🔄 Flaky Test Detected

Analysis: e2e TestApiPg/TestQRep timed out after the catalog PostgreSQL connection was killed mid-test with SQLSTATE 57P01 (admin_shutdown), a transient infrastructure failure caused by resource contention from 32 parallel tests.
Confidence: 0.92

✅ Automatically retrying the workflow

View workflow run

When mysql connector is set up with ssh tunnel, there is a possible deadlock observed where the syncer is never closed and PullRecords hangs indefinitely. ``` | 2026-04-10 23:09:01.794180854 | INFO | [mysql] PullRecords finished streaming | | 2026-04-10 23:09:01.794210647 | INFO | syncer is closing... | | 2026-04-10 23:09:01.794213666 | WARN | could not set read deadline | | 2026-04-10 23:09:01.835046706 | INFO | written records to OCF | | 2026-04-10 23:09:01.868201938 | ERROR | kill connection | | 2026-04-10 23:09:01.868229754 | INFO | kill last connection | | 2026-04-10 23:10:01.834992414 | INFO | written records to OCF | | 2026-04-10 23:11:01.835059135 | INFO | written records to OCF | | 2026-04-10 23:12:01.835527845 | INFO | written records to OCF | | 2026-04-10 23:13:01.834876775 | INFO | written records to OCF | | 2026-04-10 23:14:01.835584592 | INFO | written records to OCF | ... ``` Notice the `could not set read deadline` warning, and the `kill connection` error, both coming from mysql binlogSyncer: - the `could not set read deadline` is failing with error message "ssh: tcpChan: deadline not supported" - the `kill connection` is failing with error message ""error":"ERROR 1094 (HY000): Unknown thread id: 743468"" What happened here is the library we are using for processing mysql replication, go-msyql, has a bug that can manifest if it's using SSH tunnel and if the thread is already reaped by the MySQL server. This let the `syncer.Close()` to hang indefinitely waiting because go-mysql thinks the connection is still alive (and the ssh tunneling connection very much is) so it gets stuck on `wg.Wait()` inside `BinlogSyncer.close()` This is a different case than #4067, because SSH tunnel itself is healthy. --------- Co-authored-by: Ilia Demianenko <ilia.demianenko@clickhouse.com>

ilidemi added 2 commits March 17, 2026 18:49

Fix MySQL CDC hang when SSH tunnel dies

e8c3270

use logger with more context

6035380

ilidemi added 2 commits March 18, 2026 22:19

Use non-temporal logger

8ca5377

lint

50f0554

ilidemi added 2 commits April 8, 2026 08:00

Merge tag 'v0.36.16' into customer-mysql-cdc-keepalive

3312041

Merge branch 'main' into customer-mysql-cdc-keepalive

c3fcdc8

ilidemi marked this pull request as ready for review April 10, 2026 03:17

ilidemi requested a review from jgao54 April 10, 2026 03:17

pfcoperez mentioned this pull request Apr 13, 2026

Sample reports pfcoperez/whatsgoingon#1

Open

Merge branch 'main' into customer-mysql-cdc-keepalive

651aa70

Update tilt ports

c43a2c2

jgao54 reviewed Apr 15, 2026

View reviewed changes

jgao54 approved these changes Apr 15, 2026

View reviewed changes

jgao54 reviewed Apr 15, 2026

View reviewed changes

Comment thread flow/connectors/mysql/ssh_keepalive_test.go

Parallel tests

425d3f9

ilidemi enabled auto-merge (squash) April 15, 2026 04:39

ilidemi merged commit 3ecdad2 into main Apr 15, 2026
25 of 28 checks passed

ilidemi deleted the customer-mysql-cdc-keepalive branch April 15, 2026 05:50

jgao54 mentioned this pull request Apr 18, 2026

fix mysql stuck on syncer.Close() #4195

Merged

Uh oh!

Conversation

ilidemi commented Mar 18, 2026

Uh oh!

codecov Bot commented Mar 18, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

❌ 2 Tests Failed:

Uh oh!

github-actions Bot commented Mar 18, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Mar 18, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Mar 19, 2026

🔄 Flaky Test Detected

Uh oh!

ilidemi commented Mar 25, 2026

Uh oh!

ilidemi commented Apr 10, 2026

Uh oh!

github-actions Bot commented Apr 10, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Apr 14, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Apr 14, 2026

🔄 Flaky Test Detected

Uh oh!

jgao54 Apr 15, 2026

Choose a reason for hiding this comment

Uh oh!

ilidemi Apr 15, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

github-actions Bot commented Apr 15, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Apr 15, 2026

🔄 Flaky Test Detected

Uh oh!

github-actions Bot commented Apr 15, 2026

🔄 Flaky Test Detected

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

codecov Bot commented Mar 18, 2026 •

edited

Loading