add_debug_log.diff
application/octet-stream
Filename: add_debug_log.diff
Type: application/octet-stream
Part: 2
Message:
RE: speed up a logical replica setup
Patch
Same data as JSON:
GET /api/v1/attachments/:id/patch
the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes.
API reference →
Format: unified
| File | + | − |
|---|---|---|
| src/bin/pg_basebackup/pg_subscriber.c | 190 | 0 |
diff --git a/src/bin/pg_basebackup/pg_subscriber.c b/src/bin/pg_basebackup/pg_subscriber.c
index 355738c..290be7c 100644
--- a/src/bin/pg_basebackup/pg_subscriber.c
+++ b/src/bin/pg_basebackup/pg_subscriber.c
@@ -675,13 +675,66 @@ create_all_logical_replication_slots(PrimaryInfo *primary,
get_subscription_name(perdb->oid, (int) getpid(), replslotname, NAMEDATALEN);
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a replication slot %s start: %s", replslotname, timebuf);
+ }
+
/* Create replication slot on publisher. */
if (create_logical_replication_slot(conn, false, perdb) == NULL && !dry_run)
return false;
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a replication slot %s end: %s", replslotname, timebuf);
+ }
+
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a publication start: %s", timebuf);
+ }
+
/* Also create a publication */
create_publication(conn, primary, perdb);
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a publication end: %s", timebuf);
+ }
+
disconnect_database(conn);
}
@@ -839,6 +892,19 @@ wait_for_end_recovery(const char *base_conninfo, const char *dbname)
if (conn == NULL)
exit(1);
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a wait_for start: %s", timebuf);
+ }
+
for (cnt = 0; cnt < wait_seconds * WAITS_PER_SEC; cnt++)
{
bool in_recovery;
@@ -875,6 +941,19 @@ wait_for_end_recovery(const char *base_conninfo, const char *dbname)
pg_usleep(USEC_PER_SEC / WAITS_PER_SEC);
}
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a wait_for stop: %s", timebuf);
+ }
+
disconnect_database(conn);
/*
@@ -1059,6 +1138,19 @@ create_subscription(PGconn *conn, StandbyInfo *standby, char *base_conninfo,
pg_log_debug("command is: %s", str->data);
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a subscription %s start: %s", subname, timebuf);
+ }
+
if (!dry_run)
{
res = PQexec(conn, str->data);
@@ -1071,6 +1163,19 @@ create_subscription(PGconn *conn, StandbyInfo *standby, char *base_conninfo,
}
}
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("creating a subscription %s end: %s", subname, timebuf);
+ }
+
/* for cleanup purposes */
perdb->made_subscription = true;
@@ -1277,8 +1382,35 @@ start_standby_server(StandbyInfo *standby, unsigned short subport,
pg_ctl_cmd = psprintf("\"%s/pg_ctl\" start -D \"%s\" -s -o \"-p %d\" -l \"%s\"",
standby->bindir,
standby->pgdata, subport, server_start_log);
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl start begin: %s", timebuf);
+ }
+
rc = system(pg_ctl_cmd);
pg_ctl_status(pg_ctl_cmd, rc, 1);
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl start end: %s", timebuf);
+ }
}
static char *
@@ -1723,8 +1855,38 @@ main(int argc, char **argv)
pg_ctl_cmd = psprintf("\"%s/pg_ctl\" stop -D \"%s\" -s",
standby.bindir, standby.pgdata);
+
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl stop begin: %s", timebuf);
+ }
+
+
rc = system(pg_ctl_cmd);
pg_ctl_status(pg_ctl_cmd, rc, 0);
+
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl stop end: %s", timebuf);
+ }
}
/*
@@ -1756,6 +1918,7 @@ main(int argc, char **argv)
consistent_lsn = create_logical_replication_slot(conn, true,
&dbarr.perdb[0]);
+
/*
* Write recovery parameters.
*
@@ -1856,9 +2019,36 @@ main(int argc, char **argv)
pg_ctl_cmd = psprintf("\"%s/pg_ctl\" stop -D \"%s\" -s",
standby.bindir, standby.pgdata);
+
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl stop for subscriber begin: %s", timebuf);
+ }
+
rc = system(pg_ctl_cmd);
pg_ctl_status(pg_ctl_cmd, rc, 0);
+ {
+ char timebuf[128];
+ struct timeval time;
+ time_t tt;
+
+ gettimeofday(&time, NULL);
+ tt = (time_t) time.tv_sec;
+ strftime(timebuf, sizeof(timebuf), "%H%M%S", localtime(&tt));
+ snprintf(timebuf + strlen(timebuf), sizeof(timebuf) - strlen(timebuf),
+ ".%03d", (int) (time.tv_usec / 1000));
+ pg_log_warning("pg_ctl stop for subscriber end: %s", timebuf);
+ }
+
/*
* Change system identifier.
*/