Skip to content

Commit c1ef83c

Browse files
knizhnikknizhnik
committed
Add recovery test
1 parent 1dddd25 commit c1ef83c

File tree

5 files changed

+23
-23
lines changed

5 files changed

+23
-23
lines changed

‎contrib/mmts/bgwpool.c

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,8 +30,6 @@ static void BgwPoolMainLoop(Datum arg)
3030
BackgroundWorkerUnblockSignals();
3131
BackgroundWorkerInitializeConnection(pool->dbname, NULL);
3232

33-
elog(WARNING, "Start background worker %d", id);
34-
3533
while(true) {
3634
PGSemaphoreLock(&pool->available);
3735
SpinLockAcquire(&pool->lock);

‎contrib/mmts/check-recovery.sh

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,2 @@
1+
rm -rf /home/knizhnik/postgres_cluster/contrib/mmts/tmp_check/log
2+
TESTDIR='/home/knizhnik/postgres_cluster/contrib/mmts' PATH="/home/knizhnik/postgres_cluster/tmp_install/home/knizhnik/postgres_cluster/dist/bin:$PATH" LD_LIBRARY_PATH="/home/knizhnik/postgres_cluster/tmp_install/home/knizhnik/postgres_cluster/dist/lib:$LD_LIBRARY_PATH" PGPORT='65432' PG_REGRESS='/home/knizhnik/postgres_cluster/contrib/mmts/../../src/test/regress/pg_regress' prove -I ../../src/test/perl/ --verbose t/001_basic_recovery.pl

‎contrib/mmts/multimaster.c

Lines changed: 17 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -989,7 +989,7 @@ void MtmAbortTransaction(MtmTransState* ts)
989989

990990
void MtmRecoveryCompleted(void)
991991
{
992-
elog(WARNING, "Recovery of node %d is completed", MtmNodeId);
992+
elog(NOTICE, "Recovery of node %d is completed", MtmNodeId);
993993
MtmLock(LW_EXCLUSIVE);
994994
Mtm->recoverySlot = 0;
995995
BIT_CLEAR(Mtm->disabledNodeMask, MtmNodeId-1);
@@ -1072,12 +1072,12 @@ bool MtmRecoveryCaughtUp(int nodeId, XLogRecPtr slotLSN)
10721072
XLogRecPtr walLSN = GetXLogInsertRecPtr();
10731073
if (slotLSN == walLSN && Mtm->nActiveTransactions == 0) {
10741074
if (BIT_CHECK(Mtm->nodeLockerMask, nodeId-1)) {
1075-
elog(WARNING,"Node %d is caught-up", nodeId);
1075+
elog(NOTICE,"Node %d is caught-up", nodeId);
10761076
BIT_CLEAR(Mtm->walSenderLockerMask, MyWalSnd - WalSndCtl->walsnds);
10771077
BIT_CLEAR(Mtm->nodeLockerMask, nodeId-1);
10781078
Mtm->nLockers -= 1;
10791079
} else {
1080-
elog(WARNING,"Node %d is caugth-up without locking cluster", nodeId);
1080+
elog(NOTICE,"%d: dode %d is caugth-up without locking cluster", MyProcPid, nodeId);
10811081
/* We are lucky: caugth-up without locking cluster! */
10821082
}
10831083
BIT_CLEAR(Mtm->disabledNodeMask, nodeId-1);
@@ -1092,7 +1092,7 @@ bool MtmRecoveryCaughtUp(int nodeId, XLogRecPtr slotLSN)
10921092
* We have to maintain two bitmasks: one is marking wal sender, another - correspondent nodes.
10931093
* Is there some better way to establish mapping between nodes ad WAL-seconder?
10941094
*/
1095-
elog(WARNING,"Node %d is almost caught-up: slot position %lx, WAL position %lx, active transactions %d",
1095+
elog(NOTICE,"Node %d is almost caught-up: slot position %lx, WAL position %lx, active transactions %d",
10961096
nodeId, slotLSN, walLSN, Mtm->nActiveTransactions);
10971097
Assert(MyWalSnd != NULL); /* This function is called by WAL-sender, so it should not be NULL */
10981098
BIT_SET(Mtm->nodeLockerMask, nodeId-1);
@@ -1109,7 +1109,7 @@ bool MtmRecoveryCaughtUp(int nodeId, XLogRecPtr slotLSN)
11091109
void MtmSwitchClusterMode(MtmNodeStatus mode)
11101110
{
11111111
Mtm->status = mode;
1112-
elog(WARNING, "Switch to %s mode", MtmNodeStatusMnem[mode]);
1112+
elog(NOTICE, "Switch to %s mode", MtmNodeStatusMnem[mode]);
11131113
/* ??? Something else to do here? */
11141114
}
11151115

@@ -1137,7 +1137,7 @@ MtmCheckClusterLock()
11371137
break;
11381138
} else {
11391139
/* recovered replica catched up with master */
1140-
elog(WARNING, "WAL-sender %d complete recovery", i);
1140+
elog(NOTICE, "WAL-sender %d complete recovery", i);
11411141
BIT_CLEAR(Mtm->walSenderLockerMask, i);
11421142
}
11431143
}
@@ -1156,7 +1156,7 @@ MtmCheckClusterLock()
11561156
} else {
11571157
/* All lockers are synchronized their logs */
11581158
/* Remove lock and mark them as receovered */
1159-
elog(WARNING, "Complete recovery of %d nodes (node mask %lx)", Mtm->nLockers, (long) Mtm->nodeLockerMask);
1159+
elog(NOTICE, "Complete recovery of %d nodes (node mask %lx)", Mtm->nLockers, (long) Mtm->nodeLockerMask);
11601160
Assert(Mtm->walSenderLockerMask == 0);
11611161
Assert((Mtm->nodeLockerMask & Mtm->disabledNodeMask) == Mtm->nodeLockerMask);
11621162
Mtm->disabledNodeMask &= ~Mtm->nodeLockerMask;
@@ -1216,7 +1216,7 @@ bool MtmRefreshClusterStatus(bool nowait)
12161216

12171217
clique = MtmFindMaxClique(matrix, MtmNodes, &clique_size);
12181218
if (clique_size >= MtmNodes/2+1) { /* have quorum */
1219-
elog(WARNING, "Find clique %lx, disabledNodeMask %lx", (long) clique, (long) Mtm->disabledNodeMask);
1219+
elog(NOTICE, "Find clique %lx, disabledNodeMask %lx", (long) clique, (long) Mtm->disabledNodeMask);
12201220
MtmLock(LW_EXCLUSIVE);
12211221
mask = ~clique & (((nodemask_t)1 << MtmNodes)-1) & ~Mtm->disabledNodeMask; /* new disabled nodes mask */
12221222
for (i = 0; mask != 0; i++, mask >>= 1) {
@@ -1244,7 +1244,7 @@ bool MtmRefreshClusterStatus(bool nowait)
12441244
MtmSwitchClusterMode(MTM_RECOVERY);
12451245
}
12461246
} else {
1247-
elog(WARNING, "Clique %lx has no quorum", (long) clique);
1247+
elog(NOTICE, "Clique %lx has no quorum", (long) clique);
12481248
MtmSwitchClusterMode(MTM_IN_MINORITY);
12491249
}
12501250
return true;
@@ -1259,7 +1259,7 @@ void MtmCheckQuorum(void)
12591259
}
12601260
} else {
12611261
if (Mtm->status == MTM_IN_MINORITY) {
1262-
elog(WARNING, "Node is in majority: dissbled mask %lx", (long) Mtm->disabledNodeMask);
1262+
elog(NOTICE, "Node is in majority: dissbled mask %lx", (long) Mtm->disabledNodeMask);
12631263
MtmSwitchClusterMode(MTM_ONLINE);
12641264
}
12651265
}
@@ -1286,7 +1286,7 @@ void MtmOnNodeDisconnect(int nodeId)
12861286
for (ts = Mtm->transListHead; ts != NULL; ts = ts->next) {
12871287
if (!ts->votingCompleted) {
12881288
if (ts->status != TRANSACTION_STATUS_ABORTED) {
1289-
elog(WARNING, "Rollback active transaction %d:%d", ts->gtid.node, ts->gtid.xid);
1289+
elog(NOTICE, "Rollback active transaction %d:%d", ts->gtid.node, ts->gtid.xid);
12901290
MtmAbortTransaction(ts);
12911291
}
12921292
MtmWakeUpBackend(ts);
@@ -1845,7 +1845,7 @@ MtmSlotMode MtmReceiverSlotMode(int nodeId)
18451845
recovery = true;
18461846
if (Mtm->recoverySlot == 0 || Mtm->recoverySlot == nodeId) {
18471847
/* Choose for recovery first available slot */
1848-
elog(WARNING, "Start recovery from node %d", nodeId);
1848+
elog(NOTICE, "Start recovery from node %d", nodeId);
18491849
Mtm->recoverySlot = nodeId;
18501850
return SLOT_OPEN_EXISTED;
18511851
}
@@ -1854,7 +1854,7 @@ MtmSlotMode MtmReceiverSlotMode(int nodeId)
18541854
MtmSleep(STATUS_POLL_DELAY);
18551855
}
18561856
if (recovery) {
1857-
elog(WARNING, "Recreate replication slot for node %d after end of recovery", nodeId);
1857+
elog(NOTICE, "Recreate replication slot for node %d after end of recovery", nodeId);
18581858
} else {
18591859
MTM_INFO("%d: Reuse replication slot for node %d\n", MyProcPid, nodeId);
18601860
}
@@ -1908,7 +1908,7 @@ static void
19081908
MtmOnProcExit(int code, Datum arg)
19091909
{
19101910
if (MtmReplicationNodeId >= 0) {
1911-
elog(WARNING, "WAL-sender to %d is terminated", MtmReplicationNodeId);
1911+
elog(NOTICE, "WAL-sender to %d is terminated", MtmReplicationNodeId);
19121912
MtmOnNodeDisconnect(MtmReplicationNodeId);
19131913
}
19141914
}
@@ -1939,15 +1939,15 @@ MtmReplicationStartupHook(struct PGLogicalStartupHookArgs* args)
19391939
}
19401940
MtmLock(LW_EXCLUSIVE);
19411941
if (MtmIsRecoverySession) {
1942-
elog(WARNING, "%d: Node %d start recovery of node %d", MyProcPid, MtmNodeId, MtmReplicationNodeId);
1942+
elog(NOTICE, "%d: Node %d start recovery of node %d", MyProcPid, MtmNodeId, MtmReplicationNodeId);
19431943
if (!BIT_CHECK(Mtm->disabledNodeMask, MtmReplicationNodeId-1)) {
19441944
BIT_SET(Mtm->disabledNodeMask, MtmReplicationNodeId-1);
19451945
Mtm->nNodes -= 1;
19461946
MtmCheckQuorum();
19471947
}
19481948
} else if (BIT_CHECK(Mtm->disabledNodeMask, MtmReplicationNodeId-1)) {
19491949
if (recoveryCompleted) {
1950-
elog(WARNING, "Node %d consider that recovery of node %d is completed: start normal replication", MtmNodeId, MtmReplicationNodeId);
1950+
elog(NOTICE, "Node %d consider that recovery of node %d is completed: start normal replication", MtmNodeId, MtmReplicationNodeId);
19511951
BIT_CLEAR(Mtm->disabledNodeMask, MtmReplicationNodeId-1);
19521952
Mtm->nNodes += 1;
19531953
MtmCheckQuorum();
@@ -1965,7 +1965,7 @@ static void
19651965
MtmReplicationShutdownHook(struct PGLogicalShutdownHookArgs* args)
19661966
{
19671967
if (MtmReplicationNodeId >= 0) {
1968-
elog(WARNING, "Logical replication to node %d is stopped", MtmReplicationNodeId);
1968+
elog(NOTICE, "Logical replication to node %d is stopped", MtmReplicationNodeId);
19691969
MtmOnNodeDisconnect(MtmReplicationNodeId);
19701970
MtmReplicationNodeId = -1; /* defuse on_proc_exit hook */
19711971
}
@@ -2412,7 +2412,6 @@ static bool MtmTwoPhaseCommit(MtmCurrentTrans* x)
24122412
if (!x->isReplicated && (x->isDistributed && x->containsDML)) {
24132413
MtmGenerateGid(x->gid);
24142414
if (!x->isTransactionBlock) {
2415-
/* elog(WARNING, "Start transaction block for %s", x->gid); */
24162415
BeginTransactionBlock();
24172416
x->isTransactionBlock = true;
24182417
CommitTransactionCommand();

‎contrib/mmts/pglogical_proto.c

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -150,6 +150,7 @@ pglogical_write_commit(StringInfo out, PGLogicalOutputData *data,
150150
return;
151151
}
152152
if (MtmRecoveryCaughtUp(MtmReplicationNodeId, txn->end_lsn)) {
153+
elog(NOTICE, "wal-sender complete recovery of node %d at LSN(commit %lx, end %lx, log %lx) in transaction %s event %d", MtmReplicationNodeId, commit_lsn, txn->end_lsn, GetXLogInsertRecPtr(), txn->gid, flags);
153154
flags |= PGLOGICAL_CAUGHT_UP;
154155
}
155156
}
@@ -418,7 +419,7 @@ pglogical_init_api(PGLogicalProtoType typ)
418419
{
419420
PGLogicalProtoAPI* res = palloc0(sizeof(PGLogicalProtoAPI));
420421
sscanf(MyReplicationSlot->data.name.data, MULTIMASTER_SLOT_PATTERN, &MtmReplicationNodeId);
421-
elog(WARNING, "%d: PRGLOGICAL init API for slot %s node %d", MyProcPid, MyReplicationSlot->data.name.data, MtmReplicationNodeId);
422+
elog(LOG, "%d: PRGLOGICAL init API for slot %s node %d", MyProcPid, MyReplicationSlot->data.name.data, MtmReplicationNodeId);
422423
res->write_rel = pglogical_write_rel;
423424
res->write_begin = pglogical_write_begin;
424425
res->write_commit = pglogical_write_commit;

‎contrib/mmts/pglogical_receiver.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -292,10 +292,10 @@ pglogical_receiver_main(Datum main_arg)
292292
* So we assume that LSNs are the same for local and remote node
293293
*/
294294
originStartPos = Mtm->status == MTM_RECOVERY ? GetXLogInsertRecPtr() : 0;
295-
elog(WARNING, "Start logical receiver at position %lx from node %d", originStartPos, args->remote_node);
295+
elog(NOTICE, "Start logical receiver at position %lx from node %d", originStartPos, args->remote_node);
296296
} else {
297297
originStartPos = replorigin_get_progress(originId, false);
298-
elog(WARNING, "Restart logical receiver at position %lx from node %d", originStartPos, args->remote_node);
298+
elog(NOTICE, "Restart logical receiver at position %lx from node %d", originStartPos, args->remote_node);
299299
}
300300
CommitTransactionCommand();
301301

0 commit comments

Comments
 (0)