Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unable to set up replication #332

Open
deathemperor opened this issue May 31, 2024 · 5 comments
Open

Unable to set up replication #332

deathemperor opened this issue May 31, 2024 · 5 comments
Labels
customer issue replication

Comments

@deathemperor
Copy link

deathemperor commented May 31, 2024 •
edited
Loading

I've tried with 2 types of OS without success, each with its own problem. Both are doltgres 0.7.5

Ubuntu 20.04:

config.yaml:

listener:
  host: 127.0.0.1
  port: 5455
postgres_replication:
  postgres_server_address: 127.0.0.1
  postgres_user: postgres
  postgres_password: 123456
  postgres_database: postgres
  postgres_port: 5433
  slot_name: doltgres_slot_test
behavior:
  dolt_transaction_commit: true
log_level: debug

log of running doltgres --data-dir /vol2/dolgresql/data

Starting replication
INFO[0000] Server ready. Accepting connections.
WARN[0000] secure_file_priv is set to "", which is insecure.
WARN[0000] Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read.
WARN[0000] Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory.
INFO[0000] NewConnection                                 DisableClientMultiStatements=false connectionID=1
INFO[0000] NewConnection                                 DisableClientMultiStatements=false connectionID=2
INFO[0000] ConnectionClosed                              connectionID=1
DEBU[0000] Starting query                                connectTime="2024-05-31 08:05:51.039836801 +0000 UTC m=+0.077038967" connectionID=2 query="USE `doltgres`;"
DEBU[0000] Query finished in 0 ms                        connectTime="2024-05-31 08:05:51.039836801 +0000 UTC m=+0.077038967" connectionDb=doltgres connectionID=2 query="USE `doltgres`;"
2024/05/31 08:05:51 Starting replicator
2024/05/31 08:05:51 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:05:51 Logical replication started on slot doltgres_slot_test
2024/05/31 08:05:51 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:05:51.047129 +0000 UTC ReplyRequested: false
2024/05/31 08:05:51 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:05:51.047342 +0000 UTC ReplyRequested: false
2024/05/31 08:06:01 Error: write failed: write tcp 127.0.0.1:43912->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:06:01 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:06:01 Logical replication started on slot doltgres_slot_test
2024/05/31 08:06:01 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:01 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:06:01.047826 +0000 UTC ReplyRequested: false
2024/05/31 08:06:01 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:01.049908 +0000 UTC ReplyRequested: false
2024/05/31 08:06:11 Error: write failed: write tcp 127.0.0.1:59418->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:06:11 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:06:11 Logical replication started on slot doltgres_slot_test
2024/05/31 08:06:11 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:11 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:11.057484 +0000 UTC ReplyRequested: false
2024/05/31 08:06:21 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:21 Error: conn busy. Retrying
2024/05/31 08:06:21 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:06:21 Logical replication started on slot doltgres_slot_test
2024/05/31 08:06:21 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:06:21.066913 +0000 UTC ReplyRequested: false
2024/05/31 08:06:21 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:21.067196 +0000 UTC ReplyRequested: false
2024/05/31 08:06:31 Error: write failed: write tcp 127.0.0.1:39032->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:06:31 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:06:31 Logical replication started on slot doltgres_slot_test
2024/05/31 08:06:31 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:31 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:06:31.063825 +0000 UTC ReplyRequested: false
2024/05/31 08:06:31 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:31.065772 +0000 UTC ReplyRequested: false
2024/05/31 08:06:41 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:41 Error: conn busy. Retrying
2024/05/31 08:06:41 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:06:41 Logical replication started on slot doltgres_slot_test
2024/05/31 08:06:41 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:06:41.072082 +0000 UTC ReplyRequested: false
2024/05/31 08:06:41 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:41.072171 +0000 UTC ReplyRequested: false
2024/05/31 08:06:51 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:06:51 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:06:51.065432 +0000 UTC ReplyRequested: false
2024/05/31 08:07:01 Error: write failed: write tcp 127.0.0.1:56734->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:07:01 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:07:01 Logical replication started on slot doltgres_slot_test
2024/05/31 08:07:01 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:07:01 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:07:01.074074 +0000 UTC ReplyRequested: false
2024/05/31 08:07:11 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:07:11 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:07:11.074933 +0000 UTC ReplyRequested: false
2024/05/31 08:07:21 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:07:21 Error: conn busy. Retrying
2024/05/31 08:07:21 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:07:21 Logical replication started on slot doltgres_slot_test
2024/05/31 08:07:21 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:07:21.08955 +0000 UTC ReplyRequested: false
2024/05/31 08:07:21 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:07:21.089704 +0000 UTC ReplyRequested: false
2024/05/31 08:07:31 Error: write failed: write tcp 127.0.0.1:51928->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:07:31 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:07:31 Logical replication started on slot doltgres_slot_test
2024/05/31 08:07:31 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:07:31 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:07:31.082044 +0000 UTC ReplyRequested: false
2024/05/31 08:07:31 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:07:31.082326 +0000 UTC ReplyRequested: false
2024/05/31 08:07:41 Error: write failed: write tcp 127.0.0.1:39222->127.0.0.1:5433: i/o timeout. Retrying
2024/05/31 08:07:41 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/05/31 08:07:41 Logical replication started on slot doltgres_slot_test
2024/05/31 08:07:41 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 4/C62022B9
2024/05/31 08:07:41 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-05-31 08:07:41.088457 +0000 UTC ReplyRequested: false
2024/05/31 08:07:41 Primary Keepalive Message => ServerWALEnd: 4/C62022B8 ServerTime: 2024-05-31 08:07:41.088672 +0000 UTC ReplyRequested: false
2024/05/31 08:07:51 Error during replication: write failed: write tcp 127.0.0.1:58328->127.0.0.1:5433: i/o timeout
2024/05/31 08:07:51 shutting down replicator
DEBU[0120] Received message: Terminate
INFO[0120] ConnectionClosed                              connectionID=2

I followed replication instruction here: https://docs.doltgres.com/guides/replication-from-postgres. Trying to test with employees table

=================================

MacOS M3 Max version 14.5

config.yaml:

listener:
  host: 127.0.0.1
  port: 5456
postgres_replication:
  postgres_server_address: 127.0.0.11
  postgres_user: postgres1
  postgres_password: password1
  postgres_database: postgres1
  postgres_port: 54322
  slot_name: doltgres_slot_test2
behavior:
  dolt_transaction_commit: true

logs of running doltgres -config config.yaml

Starting replication
INFO[0000] Server ready. Accepting connections.
WARN[0000] secure_file_priv is set to "", which is insecure.
WARN[0000] Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read.
WARN[0000] Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory.

It's supposed to throw error because the postgres_server_address and its info is incorrect, as well as slot name. In Ubuntu it's able to throw connection error if doltgres has trouble connecting. I set the config to incorrect info for troubleshooting after running the cli but no similar logs output found comparing to the ubuntu's.
@zachmu
Copy link
Member

zachmu commented Jun 3, 2024

Hi @deathemperor,

From the first log sample, it looks like the replica is receiving replication events from Postgres, but then it can't send its response. Is there anything in the postgres log to indicate what's happening? We haven't seen this failure mode in any of our testing. What version of Postgres are you running? And what does the pg_replication_slots table have in it?

https://www.postgresql.org/docs/16/view-pg-replication-slots.html

We haven't tried running our replica tests on Mac yet, only Ubuntu. We'll see if we can reproduce that.

Also happy to help you debug this in real time on our discord, come on by whenever you have a chance.

https://discord.com/invite/RFwfYpu

@deathemperor
Copy link
Author

deathemperor commented Jun 4, 2024 •
edited
Loading

hey @zachmu,

More details as requested:

Postgres log 2024-06-04 01:57:19.326 UTC [3147] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:21.869 UTC [3151] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:57:21.869 UTC [3151] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:57:21.869 UTC [3151] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:21.869 UTC [3151] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:57:21.869 UTC [3151] DETAIL: There are no running transactions. 2024-06-04 01:57:21.869 UTC [3151] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:31.868 UTC [3153] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:57:31.868 UTC [3153] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:57:31.868 UTC [3153] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:31.868 UTC [3153] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:57:31.868 UTC [3153] DETAIL: There are no running transactions. 2024-06-04 01:57:31.868 UTC [3153] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:41.876 UTC [3156] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:57:41.876 UTC [3156] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:57:41.876 UTC [3156] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:41.876 UTC [3156] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:57:41.876 UTC [3156] DETAIL: There are no running transactions. 2024-06-04 01:57:41.876 UTC [3156] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:51.884 UTC [3165] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:57:51.884 UTC [3165] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:57:51.884 UTC [3165] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:51.884 UTC [3165] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:57:51.884 UTC [3165] DETAIL: There are no running transactions. 2024-06-04 01:57:51.884 UTC [3165] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:57:56.899 UTC [3167] FATAL: role "root" does not exist 2024-06-04 01:58:03.732 UTC [3171] FATAL: role "root" does not exist 2024-06-04 01:58:11.892 UTC [3175] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:58:11.892 UTC [3175] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:58:11.892 UTC [3175] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:11.892 UTC [3175] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:58:11.892 UTC [3175] DETAIL: There are no running transactions. 2024-06-04 01:58:11.892 UTC [3175] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:31.900 UTC [3179] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:58:31.900 UTC [3179] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:58:31.900 UTC [3179] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:31.900 UTC [3179] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:58:31.900 UTC [3179] DETAIL: There are no running transactions. 2024-06-04 01:58:31.900 UTC [3179] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:41.907 UTC [3182] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:58:41.907 UTC [3182] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:58:41.907 UTC [3182] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:41.907 UTC [3182] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:58:41.907 UTC [3182] DETAIL: There are no running transactions. 2024-06-04 01:58:41.907 UTC [3182] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:51.913 UTC [3184] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:58:51.913 UTC [3184] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:58:51.913 UTC [3184] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:58:51.913 UTC [3184] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:58:51.913 UTC [3184] DETAIL: There are no running transactions. 2024-06-04 01:58:51.913 UTC [3184] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:59:01.920 UTC [3187] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:59:01.920 UTC [3187] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:59:01.920 UTC [3187] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:59:01.921 UTC [3187] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:59:01.921 UTC [3187] DETAIL: There are no running transactions. 2024-06-04 01:59:01.921 UTC [3187] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:59:11.927 UTC [3189] LOG: starting logical decoding for slot "doltgres_slot_test" 2024-06-04 01:59:11.927 UTC [3189] DETAIL: Streaming transactions committing after 0/1, reading WAL from 4/C6201FD8. 2024-06-04 01:59:11.927 UTC [3189] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true') 2024-06-04 01:59:11.927 UTC [3189] LOG: logical decoding found consistent point at 4/C6201FD8 2024-06-04 01:59:11.927 UTC [3189] DETAIL: There are no running transactions. 2024-06-04 01:59:11.927 UTC [3189] STATEMENT: START_REPLICATION SLOT doltgres_slot_test LOGICAL 0/1 (proto_version '2', publication_names 'doltgres_slot_test', messages 'true', streaming 'true')

Postgres version:
PostgreSQL 15.4 (Debian 15.4-2.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit

result of pg_replication_slots

postgres=# SELECT * FROM pg_stat_replication;
 pid  | usesysid | usename  | application_name | client_addr | client_hostname | client_port |         backend_start         | backend_xmin |   state   |  sent_lsn  | write_lsn | flush_lsn | replay_lsn | write_lag | flush_lag | replay_lag | sync_priority | sync_state |          reply_time
------+----------+----------+------------------+-------------+-----------------+-------------+-------------------------------+--------------+-----------+------------+-----------+-----------+------------+-----------+-----------+------------+---------------+------------+-------------------------------
 3179 |       10 | postgres |                  | 172.23.0.1  |                 |       56616 | 2024-06-04 01:58:31.897029+00 |              | streaming | 4/C6202450 | 0/1       | 0/1       | 4/C6202451 |           |           |            |             0 | async      | 2024-06-04 01:58:31.900897+00

@zachmu
Copy link
Member

zachmu commented Jun 5, 2024

Nothing here looks super suspicious to me. I think what we'll try here is making sending the standby messages more resilient, so replication doesn't die or restart when it can't send the standby messages. We'll have that out for you to try in a couple days.

@deathemperor
Copy link
Author

@zachmu any update?

@deathemperor
Copy link
Author

deathemperor commented Nov 28, 2024 •
edited
Loading

I was able to set up and got it running on my machine but the same error still occurs on my development server.

doltgres log

INFO[0000] Server ready. Accepting connections.
WARN[0000] secure_file_priv is set to "", which is insecure.
WARN[0000] Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read.
WARN[0000] Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory.
Starting replication
INFO[0000] NewConnection DisableClientMultiStatements=true connectionID=1
INFO[0000] NewConnection DisableClientMultiStatements=true connectionID=2
INFO[0000] ConnectionClosed connectionID=1
DEBU[0000] Starting query connectTime="2024-11-28 17:02:39.259995742 +0000 UTC m=+0.083332843" connectionID=2 query="SET database TO 'postgres';"
DEBU[0000] Query finished in 0 ms connectTime="2024-11-28 17:02:39.259995742 +0000 UTC m=+0.083332843" connectionDb=postgres connectionID=2 query="SET database TO 'postgres';"
2024/11/28 17:02:39 Starting replicator
2024/11/28 17:02:39 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:02:39 Logical replication started on slot doltgres_slot_test
2024/11/28 17:02:39 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:02:39.266767 +0000 UTC ReplyRequested: false
2024/11/28 17:02:39 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:02:39.334468 +0000 UTC ReplyRequested: false
2024/11/28 17:02:49 Error: write failed: write tcp 127.0.0.1:56018->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:02:49 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:02:49 Logical replication started on slot doltgres_slot_test
2024/11/28 17:02:49 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:02:49 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:02:49.264908 +0000 UTC ReplyRequested: false
2024/11/28 17:02:49 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:02:49.328845 +0000 UTC ReplyRequested: false
2024/11/28 17:02:59 Error: write failed: write tcp 127.0.0.1:58036->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:02:59 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:02:59 Logical replication started on slot doltgres_slot_test
2024/11/28 17:02:59 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:02:59 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:02:59.272326 +0000 UTC ReplyRequested: false
2024/11/28 17:02:59 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:02:59.336447 +0000 UTC ReplyRequested: false
2024/11/28 17:03:09 Error: write failed: write tcp 127.0.0.1:59162->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:03:09 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:03:09 Logical replication started on slot doltgres_slot_test
2024/11/28 17:03:09 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:09 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:03:09.278865 +0000 UTC ReplyRequested: false
2024/11/28 17:03:09 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:09.34409 +0000 UTC ReplyRequested: false
2024/11/28 17:03:19 Error: write failed: write tcp 127.0.0.1:59268->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:03:19 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:03:19 Logical replication started on slot doltgres_slot_test
2024/11/28 17:03:19 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:19 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:03:19.287235 +0000 UTC ReplyRequested: false
2024/11/28 17:03:19 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:19.352223 +0000 UTC ReplyRequested: false
2024/11/28 17:03:29 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:29 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:29.28777 +0000 UTC ReplyRequested: false
2024/11/28 17:03:39 Error: write failed: write tcp 127.0.0.1:42678->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:03:39 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:03:39 Logical replication started on slot doltgres_slot_test
2024/11/28 17:03:39 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:39 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:03:39.295015 +0000 UTC ReplyRequested: false
2024/11/28 17:03:39 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:39.360473 +0000 UTC ReplyRequested: false
2024/11/28 17:03:49 Error: write failed: write tcp 127.0.0.1:43582->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:03:49 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:03:49 Logical replication started on slot doltgres_slot_test
2024/11/28 17:03:49 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:49 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:49.373751 +0000 UTC ReplyRequested: false
2024/11/28 17:03:59 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:03:59 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:03:59.30782 +0000 UTC ReplyRequested: false
2024/11/28 17:04:09 Error: write failed: write tcp 127.0.0.1:54034->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:04:09 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:04:09 Logical replication started on slot doltgres_slot_test
2024/11/28 17:04:09 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:04:09 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:04:09.320156 +0000 UTC ReplyRequested: false
2024/11/28 17:04:09 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:04:09.384399 +0000 UTC ReplyRequested: false
2024/11/28 17:04:19 Error: write failed: write tcp 127.0.0.1:53776->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:04:19 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:04:19 Logical replication started on slot doltgres_slot_test
2024/11/28 17:04:19 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:04:19 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:04:19.393046 +0000 UTC ReplyRequested: false
2024/11/28 17:04:29 Error: write failed: write tcp 127.0.0.1:42176->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:04:29 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:04:29 Logical replication started on slot doltgres_slot_test
2024/11/28 17:04:29 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:04:29 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:04:29.335937 +0000 UTC ReplyRequested: false
2024/11/28 17:04:29 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:04:29.399914 +0000 UTC ReplyRequested: false
DEBU[0120] starting statistics refresh check for 'postgres': 2024-11-28 17:04:39.249943929 +0000 UTC m=+120.073281032
DEBU[0120] statistics refresh: new table hash: 52qkcc17dcqtblc9aml4so2jrooun338
DEBU[0120] statistics refresh: new table hash: 52qkcc17dcqtblc9aml4so2jrooun338
DEBU[0120] statistics refresh: new table hash: 52qkcc17dcqtblc9aml4so2jrooun338
DEBU[0120] statistics refresh index: postgres.test.primary
DEBU[0120] statistics current: 0, new: 0, delete: 0
DEBU[0120] starting statistics refresh check for 'doltgres': 2024-11-28 17:04:39.257992379 +0000 UTC m=+120.081329569
2024/11/28 17:04:39 Error: write failed: write tcp 127.0.0.1:46724->127.0.0.1:5436: i/o timeout. Retrying
2024/11/28 17:04:39 Starting logical replication on slot doltgres_slot_test at WAL location 0/1
2024/11/28 17:04:39 Logical replication started on slot doltgres_slot_test
2024/11/28 17:04:39 Sent Standby status message with WALWritePosition = 0/1, WALApplyPosition = 5/553334B9
2024/11/28 17:04:39 Primary Keepalive Message => ServerWALEnd: 0/1 ServerTime: 2024-11-28 17:04:39.34309 +0000 UTC ReplyRequested: false
2024/11/28 17:04:39 Primary Keepalive Message => ServerWALEnd: 5/553334B8 ServerTime: 2024-11-28 17:04:39.408008 +0000 UTC ReplyRequested: false

specifically the Error: write failed: write tcp 127.0.0.1:34974->127.0.0.1:5436: i/o timeout. Retrying is the same from previous message. 5436 is the postgres main I'm trying to replicate from

config.yaml

listener:
  host: 127.0.0.1
  port: 5455
postgres_replication:
  postgres_server_address: localhost
  postgres_user: postgres
  postgres_password: 123456
  postgres_database: postgres
  postgres_port: 5436
  slot_name: doltgres_slot_test
behavior:
  dolt_transaction_commit: true
  read_only: false
log_level: debug

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
customer issue replication
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@fulghum @zachmu @deathemperor @tbantle22