From a7aa7c355418db44b23cdcb3e920bd95a9891d13 Mon Sep 17 00:00:00 2001 From: Tomas Vondra Date: Wed, 12 Mar 2025 12:40:46 +0100 Subject: [PATCH v20250312 6/6] debug --- src/backend/access/transam/xlog.c | 43 +++++++++++++++++++++++++ src/backend/postmaster/launch_backend.c | 3 ++ src/backend/storage/ipc/procsignal.c | 34 +++++++++++++++++++ src/backend/utils/init/miscinit.c | 3 ++ 4 files changed, 83 insertions(+) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 61da6d583cd..63d74e95075 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -4271,6 +4271,8 @@ InitControlFile(uint64 sysidentifier, uint32 data_checksum_version) * processes get the current value from. (Maybe it should go just there?) */ XLogCtl->data_checksum_version = data_checksum_version; + + elog(LOG, "InitControlFile %p data_checksum_version %u", XLogCtl, ControlFile->data_checksum_version); } static void @@ -4928,6 +4930,7 @@ SetDataChecksumsOff(void) bool AbsorbChecksumsOnInProgressBarrier(void) { + elog(LOG, "AbsorbChecksumsOnInProgressBarrier"); SetLocalDataChecksumVersion(PG_DATA_CHECKSUM_INPROGRESS_ON_VERSION); return true; } @@ -4935,6 +4938,7 @@ AbsorbChecksumsOnInProgressBarrier(void) bool AbsorbChecksumsOnBarrier(void) { + elog(LOG, "AbsorbChecksumsOnBarrier"); Assert(LocalDataChecksumVersion == PG_DATA_CHECKSUM_INPROGRESS_ON_VERSION); SetLocalDataChecksumVersion(PG_DATA_CHECKSUM_VERSION); return true; @@ -4943,6 +4947,7 @@ AbsorbChecksumsOnBarrier(void) bool AbsorbChecksumsOffInProgressBarrier(void) { + elog(LOG, "AbsorbChecksumsOffInProgressBarrier"); SetLocalDataChecksumVersion(PG_DATA_CHECKSUM_INPROGRESS_OFF_VERSION); return true; } @@ -4950,6 +4955,7 @@ AbsorbChecksumsOffInProgressBarrier(void) bool AbsorbChecksumsOffBarrier(void) { + elog(LOG, "AbsorbChecksumsOffBarrier"); SetLocalDataChecksumVersion(0); return true; } @@ -4979,6 +4985,7 @@ InitLocalControldata(void) void SetLocalDataChecksumVersion(uint32 data_checksum_version) { + elog(LOG, "SetLocalDataChecksumVersion %u", data_checksum_version); LocalDataChecksumVersion = data_checksum_version; switch (LocalDataChecksumVersion) @@ -5488,6 +5495,9 @@ XLOGShmemInit(void) XLogCtl->InstallXLogFileSegmentActive = false; XLogCtl->WalWriterSleeping = false; + elog(LOG, "XLogCtl->data_checksum_version %u ControlFile->data_checksum_version %u", + XLogCtl->data_checksum_version, ControlFile->data_checksum_version); + /* use the checksum info from control file */ XLogCtl->data_checksum_version = ControlFile->data_checksum_version; @@ -7512,6 +7522,8 @@ CreateCheckPoint(int flags) */ checkPoint.data_checksum_version = XLogCtl->data_checksum_version; + elog(WARNING, "CREATECHECKPOINT XLogCtl->data_checksum_version %u", XLogCtl->data_checksum_version); + if (shutdown) { XLogRecPtr curInsert = XLogBytePosToRecPtr(Insert->CurrBytePos); @@ -7767,6 +7779,10 @@ CreateCheckPoint(int flags) ControlFile->minRecoveryPoint = InvalidXLogRecPtr; ControlFile->minRecoveryPointTLI = 0; + elog(LOG, "CreateCheckPoint data_checksum_version %u %u", + ControlFile->data_checksum_version, + checkPoint.data_checksum_version); + /* make sure we start with the checksum version as of the checkpoint */ ControlFile->data_checksum_version = checkPoint.data_checksum_version; @@ -7917,6 +7933,10 @@ CreateEndOfRecoveryRecord(void) ControlFile->minRecoveryPoint = recptr; ControlFile->minRecoveryPointTLI = xlrec.ThisTimeLineID; + elog(LOG, "CreateEndOfRecoveryRecord data_checksum_version %u xlog %u", + ControlFile->data_checksum_version, + XLogCtl->data_checksum_version); + /* start with the latest checksum version (as of the end of recovery) */ ControlFile->data_checksum_version = XLogCtl->data_checksum_version; @@ -8127,6 +8147,9 @@ CreateRestartPoint(int flags) lastCheckPoint = XLogCtl->lastCheckPoint; SpinLockRelease(&XLogCtl->info_lck); + elog(LOG, "CreateRestartPoint lastCheckPointRecPtr %X/%X lastCheckPointEndPtr %X/%X", + LSN_FORMAT_ARGS(lastCheckPointRecPtr), LSN_FORMAT_ARGS(lastCheckPointEndPtr)); + /* * Check that we're still in recovery mode. It's ok if we exit recovery * mode after this check, the restart point is valid anyway. @@ -8263,6 +8286,10 @@ CreateRestartPoint(int flags) ControlFile->state = DB_SHUTDOWNED_IN_RECOVERY; } + elog(LOG, "CreateRestartPoint data_checksum_version %u %u", + ControlFile->data_checksum_version, + lastCheckPoint.data_checksum_version); + /* we shall start with the latest checksum version */ ControlFile->data_checksum_version = lastCheckPoint.data_checksum_version; @@ -9125,13 +9152,25 @@ xlog_redo(XLogReaderState *record) { xl_checksum_state state; uint64 barrier; + XLogRecPtr checkpointLsn; + uint32 value, + value_last; memcpy(&state, XLogRecGetData(record), sizeof(xl_checksum_state)); SpinLockAcquire(&XLogCtl->info_lck); + value_last = XLogCtl->data_checksum_version; XLogCtl->data_checksum_version = state.new_checksumtype; SpinLockRelease(&XLogCtl->info_lck); + LWLockAcquire(ControlFileLock, LW_EXCLUSIVE); + checkpointLsn = ControlFile->checkPoint; + value = ControlFile->data_checksum_version; + LWLockRelease(ControlFileLock); + + elog(LOG, "XLOG_CHECKSUMS xlog_redo %X/%X control checkpoint %X/%X control %u last %u record %u", + LSN_FORMAT_ARGS(lsn), LSN_FORMAT_ARGS(checkpointLsn), value, value_last, state.new_checksumtype); + /* * Block on a procsignalbarrier to await all processes having seen the * change to checksum status. Once the barrier has been passed we can @@ -9140,22 +9179,26 @@ xlog_redo(XLogReaderState *record) switch (state.new_checksumtype) { case PG_DATA_CHECKSUM_INPROGRESS_ON_VERSION: + elog(LOG, "XLOG_CHECKSUMS emit PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_ON"); barrier = EmitProcSignalBarrier(PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_ON); WaitForProcSignalBarrier(barrier); break; case PG_DATA_CHECKSUM_INPROGRESS_OFF_VERSION: + elog(LOG, "XLOG_CHECKSUMS emit PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_OFF"); barrier = EmitProcSignalBarrier(PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_OFF); WaitForProcSignalBarrier(barrier); break; case PG_DATA_CHECKSUM_VERSION: + elog(LOG, "XLOG_CHECKSUMS emit PROCSIGNAL_BARRIER_CHECKSUM_ON"); barrier = EmitProcSignalBarrier(PROCSIGNAL_BARRIER_CHECKSUM_ON); WaitForProcSignalBarrier(barrier); break; default: Assert(state.new_checksumtype == 0); + elog(LOG, "XLOG_CHECKSUMS emit PROCSIGNAL_BARRIER_CHECKSUM_OFF"); barrier = EmitProcSignalBarrier(PROCSIGNAL_BARRIER_CHECKSUM_OFF); WaitForProcSignalBarrier(barrier); break; diff --git a/src/backend/postmaster/launch_backend.c b/src/backend/postmaster/launch_backend.c index fc6e2c6ed41..2034c204cee 100644 --- a/src/backend/postmaster/launch_backend.c +++ b/src/backend/postmaster/launch_backend.c @@ -235,6 +235,9 @@ postmaster_child_launch(BackendType child_type, int child_slot, Assert(IsPostmasterEnvironment && !IsUnderPostmaster); + elog(LOG, "postmaster_child_launch: LocalDataChecksumVersion %u xlog %u", GetLocalDataChecksumVersion(), + GetCurrentDataChecksumVersion()); + #ifdef EXEC_BACKEND pid = internal_forkexec(child_process_kinds[child_type].name, child_slot, startup_data, startup_data_len, client_sock); diff --git a/src/backend/storage/ipc/procsignal.c b/src/backend/storage/ipc/procsignal.c index 2b13a8cd260..b88d1d07431 100644 --- a/src/backend/storage/ipc/procsignal.c +++ b/src/backend/storage/ipc/procsignal.c @@ -553,6 +553,40 @@ ProcessProcSignalBarrier(void) PG_TRY(); { + /* print info about barriers */ + { + uint32 tmp = flags; + + elog(LOG, "ProcessProcSignalBarrier flags %u", tmp); + + while (tmp != 0) + { + ProcSignalBarrierType type; + + type = (ProcSignalBarrierType) pg_rightmost_one_pos32(tmp); + switch (type) + { + case PROCSIGNAL_BARRIER_SMGRRELEASE: + elog(LOG, "PROCSIGNAL_BARRIER_SMGRRELEASE"); + break; + case PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_ON: + elog(LOG, "PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_ON"); + break; + case PROCSIGNAL_BARRIER_CHECKSUM_ON: + elog(LOG, "PROCSIGNAL_BARRIER_CHECKSUM_ON"); + break; + case PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_OFF: + elog(LOG, "PROCSIGNAL_BARRIER_CHECKSUM_INPROGRESS_OFF"); + break; + case PROCSIGNAL_BARRIER_CHECKSUM_OFF: + elog(LOG, "PROCSIGNAL_BARRIER_CHECKSUM_OFF"); + break; + } + + BARRIER_CLEAR_BIT(tmp, type); + } + } + /* * Process each type of barrier. The barrier-processing functions * should normally return true, but may return false if the diff --git a/src/backend/utils/init/miscinit.c b/src/backend/utils/init/miscinit.c index a071ba6f455..df52ce8ad7f 100644 --- a/src/backend/utils/init/miscinit.c +++ b/src/backend/utils/init/miscinit.c @@ -164,6 +164,9 @@ InitPostmasterChild(void) (errcode_for_socket_access(), errmsg_internal("could not set postmaster death monitoring pipe to FD_CLOEXEC mode: %m"))); #endif + + elog(LOG, "InitPostmasterChild: LocalDataChecksumVersion %u xlog %u", GetLocalDataChecksumVersion(), + GetCurrentDataChecksumVersion()); } /* -- 2.48.1