On Wed, Jan 19, 2022 at 9:53 PM Fabrice Chapuis fabrice636...@gmail.com<mailto:fabrice636...@gmail.com> wrote: > Hello Amit, > If it takes little work for you, can you please send me a piece of code > with the change needed to do the test
I wrote a patch(Send-keepalive.patch, please refer to attachment) according to Amit's suggestions. But after I did some simple test about this patch by the test script "test.sh"(please refer to attachment), I found the timeout problem has not been fixed by this patch. So I add some logs(please refer to Add-some-logs-to-debug.patch) to confirm newly added WalSndKeepaliveIfNecessary() send keepalive message or not. After applying the Send-keepalive.patch and Add-some-logs-to-debug.patch, I found that the added message "send keep alive message" was not printed in publisher-side log. [publisher-side log]: 2022-01-20 15:21:50.057 CST [2400278] LOG: checkpoint complete: wrote 61 buffers (0.4%); 0 WAL file(s) added, 0 removed, 0 recycled; write=9.838 s, sync=0.720 s, total=10.559 s; sync files=4, longest=0.563 s, average=0.180 s; distance=538053 kB, estimate=543889 kB 2022-01-20 15:21:50.977 CST [2400278] LOG: checkpoints are occurring too frequently (11 seconds apart) 2022-01-20 15:21:50.977 CST [2400278] HINT: Consider increasing the configuration parameter "max_wal_size". 2022-01-20 15:21:50.988 CST [2400278] LOG: checkpoint starting: wal 2022-01-20 15:21:52.853 CST [2400404] LOG: begin load changes 2022-01-20 15:21:52.853 CST [2400404] STATEMENT: START_REPLICATION SLOT "sub" LOGICAL 0/0 (proto_version '3', publication_names '"pub"') 2022-01-20 15:22:52.969 CST [2410649] ERROR: replication slot "sub" is active for PID 2400404 2022-01-20 15:22:52.969 CST [2410649] STATEMENT: START_REPLICATION SLOT "sub" LOGICAL 0/0 (proto_version '3', publication_names '"pub"') 2022-01-20 15:22:57.980 CST [2410657] ERROR: replication slot "sub" is active for PID 2400404 [subscriber-side log]: 2022-01-20 15:16:10.975 CST [2400335] LOG: checkpoint starting: time 2022-01-20 15:16:16.052 CST [2400335] LOG: checkpoint complete: wrote 51 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=4.830 s, sync=0.135 s, total=5.078 s; sync files=39, longest=0.079 s, average=0.004 s; distance=149 kB, estimate=149 kB 2022-01-20 15:22:52.738 CST [2400400] ERROR: terminating logical replication worker due to timeout 2022-01-20 15:22:52.738 CST [2400332] LOG: background worker "logical replication worker" (PID 2400400) exited with exit code 1 2022-01-20 15:22:52.740 CST [2410648] LOG: logical replication apply worker for subscription "sub" has started 2022-01-20 15:22:52.969 CST [2410648] ERROR: could not start WAL streaming: ERROR: replication slot "sub" is active for PID 2400404 2022-01-20 15:22:52.970 CST [2400332] LOG: background worker "logical replication worker" (PID 2410648) exited with exit code 1 2022-01-20 15:22:57.977 CST [2410656] LOG: logical replication apply worker for subscription "sub" has started It seems WalSndKeepaliveIfNecessary did not send keepalive message in testing. I am still doing some research about the cause. Attach the patches and test script mentioned above, in case someone wants to try. If I miss something, please let me know. Regards, Wang wei
Send-keepalive.patch
Description: Send-keepalive.patch
Add-some-logs-to-debug.patch
Description: Add-some-logs-to-debug.patch
test.sh
Description: test.sh
