035_debugging.patch
application/x-patch
Filename: 035_debugging.patch
Type: application/x-patch
Part: 0
Patch
Format: unified
| File | + | − |
|---|---|---|
| src/backend/storage/ipc/procarray.c | 87 | 2 |
| src/backend/tcop/postgres.c | 59 | 0 |
diff --git a/src/backend/storage/ipc/procarray.c b/src/backend/storage/ipc/procarray.c
index 40312df2cac..20207ca3af4 100644
--- a/src/backend/storage/ipc/procarray.c
+++ b/src/backend/storage/ipc/procarray.c
@@ -709,6 +709,28 @@ ProcArrayEndTransaction(PGPROC *proc, TransactionId latestXid)
/* be sure this is cleared in abort */
proc->delayChkptFlags = 0;
+ {
+ uint32 old_mask;
+ bool self_is_target;
+
+ /* Avoid strong read cost on the common zero case. */
+ old_mask = pg_atomic_read_u32(&proc->pendingRecoveryConflicts);
+ if (old_mask != 0)
+ {
+ old_mask = pg_atomic_read_membarrier_u32(&proc->pendingRecoveryConflicts);
+ self_is_target = (proc == MyProc);
+ if (old_mask != 0)
+ ereport(LOG,
+ (errmsg("DBG ProcArrayEndTransaction self_pid=%d "
+ "target_pid=%d target_procno=%d self_is_target=%c "
+ "clearing pendingRecoveryConflicts=0x%x",
+ getpid(), (int) proc->pid,
+ (int) GetNumberFromPGProc(proc),
+ self_is_target ? 't' : 'f',
+ old_mask)));
+ }
+ }
+
pg_atomic_write_u32(&proc->pendingRecoveryConflicts, 0);
/* must be cleared with xid/xmin: */
@@ -751,6 +773,29 @@ ProcArrayEndTransactionInternal(PGPROC *proc, TransactionId latestXid)
/* be sure this is cleared in abort */
proc->delayChkptFlags = 0;
+ {
+ uint32 old_mask;
+ bool self_is_target;
+
+ /* Avoid strong read cost on the common zero case. */
+ old_mask = pg_atomic_read_u32(&proc->pendingRecoveryConflicts);
+ if (old_mask != 0)
+ {
+ old_mask = pg_atomic_read_membarrier_u32(&proc->pendingRecoveryConflicts);
+ self_is_target = (proc == MyProc);
+ if (old_mask != 0)
+ ereport(LOG,
+ (errmsg("DBG ProcArrayEndTransactionInternal self_pid=%d "
+ "target_pid=%d target_procno=%d self_is_target=%c "
+ "clearing "
+ "pendingRecoveryConflicts=0x%x",
+ getpid(), (int) proc->pid,
+ (int) GetNumberFromPGProc(proc),
+ self_is_target ? 't' : 'f',
+ old_mask)));
+ }
+ }
+
pg_atomic_write_u32(&proc->pendingRecoveryConflicts, 0);
/* must be cleared with xid/xmin: */
@@ -910,6 +955,11 @@ void
ProcArrayClearTransaction(PGPROC *proc)
{
int pgxactoff;
+ bool log_clear = false;
+ int target_procno = INVALID_PROC_NUMBER;
+ pid_t target_pid = 0;
+ uint32 old_mask = 0;
+ bool self_is_target = false;
/*
* Currently we need to lock ProcArrayLock exclusively here, as we
@@ -934,6 +984,21 @@ ProcArrayClearTransaction(PGPROC *proc)
proc->vxid.lxid = InvalidLocalTransactionId;
proc->xmin = InvalidTransactionId;
+
+ /* Avoid strong read cost on the common zero case. */
+ old_mask = pg_atomic_read_u32(&proc->pendingRecoveryConflicts);
+ if (old_mask != 0)
+ {
+ old_mask = pg_atomic_read_membarrier_u32(&proc->pendingRecoveryConflicts);
+ if (old_mask != 0)
+ {
+ log_clear = true;
+ target_pid = proc->pid;
+ target_procno = GetNumberFromPGProc(proc);
+ self_is_target = (proc == MyProc);
+ }
+ }
+
pg_atomic_write_u32(&proc->pendingRecoveryConflicts, 0);
Assert(!(proc->statusFlags & PROC_VACUUM_STATE_MASK));
@@ -960,6 +1025,14 @@ ProcArrayClearTransaction(PGPROC *proc)
}
LWLockRelease(ProcArrayLock);
+
+ if (log_clear)
+ ereport(LOG,
+ (errmsg("DBG ProcArrayClearTransaction self_pid=%d target_pid=%d "
+ "target_procno=%d self_is_target=%c "
+ "clearing pendingRecoveryConflicts=0x%x",
+ getpid(), (int) target_pid, target_procno,
+ self_is_target ? 't' : 'f', old_mask)));
}
/*
@@ -3458,6 +3531,9 @@ bool
SignalRecoveryConflict(PGPROC *proc, pid_t pid, RecoveryConflictReason reason)
{
bool found = false;
+ int procno = INVALID_PROC_NUMBER;
+ uint32 old_mask = 0;
+ uint32 new_mask = 0;
LWLockAcquire(ProcArrayLock, LW_SHARED);
@@ -3467,15 +3543,24 @@ SignalRecoveryConflict(PGPROC *proc, pid_t pid, RecoveryConflictReason reason)
*/
if (proc->pid == pid)
{
- (void) pg_atomic_fetch_or_u32(&proc->pendingRecoveryConflicts, (1 << reason));
+ procno = GetNumberFromPGProc(proc);
+ old_mask = pg_atomic_fetch_or_u32(&proc->pendingRecoveryConflicts,
+ (1 << reason));
+ new_mask = old_mask | (1 << reason);
/* wake up the process */
- (void) SendProcSignal(pid, PROCSIG_RECOVERY_CONFLICT, GetNumberFromPGProc(proc));
+ (void) SendProcSignal(pid, PROCSIG_RECOVERY_CONFLICT, procno);
found = true;
}
LWLockRelease(ProcArrayLock);
+ if (found)
+ ereport(LOG,
+ (errmsg("DBG SignalRecoveryConflict self_pid=%d target_pid=%d "
+ "target_procno=%d reason=%d old_mask=0x%x new_mask=0x%x",
+ getpid(), pid, procno, (int) reason, old_mask, new_mask)));
+
return found;
}
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index d01a09dd0c4..862f9e960c9 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -3070,11 +3070,15 @@ FloatExceptionHandler(SIGNAL_ARGS)
* Tell the next CHECK_FOR_INTERRUPTS() to process recovery conflicts. Runs
* in a SIGUSR1 handler.
*/
+static volatile sig_atomic_t dbg_sigusr1_conflict_count = 0;
+
void
HandleRecoveryConflictInterrupt(void)
{
if (pg_atomic_read_u32(&MyProc->pendingRecoveryConflicts) != 0)
InterruptPending = true;
+ if (dbg_sigusr1_conflict_count < INT_MAX)
+ dbg_sigusr1_conflict_count++;
/* latch will be set by procsignal_sigusr1_handler */
}
@@ -3296,6 +3300,10 @@ ProcessRecoveryConflictInterrupts(void)
Assert(!proc_exit_inprogress);
Assert(InterruptHoldoffCount == 0);
+ ereport(LOG,
+ (errmsg("DBG ProcessRecoveryConflictInterrupts[%d] enter",
+ getpid())));
+
/* Are any recovery conflict pending? */
pending = pg_atomic_read_membarrier_u32(&MyProc->pendingRecoveryConflicts);
if (pending == 0)
@@ -3313,6 +3321,11 @@ ProcessRecoveryConflictInterrupts(void)
{
if ((pending & (1 << reason)) != 0)
{
+ ereport(LOG,
+ (errmsg("DBG ProcessRecoveryConflictInterrupts[%d] "
+ "dispatching reason=%d pending=0x%x",
+ getpid(), (int) reason, pending)));
+
/* clear the flag */
(void) pg_atomic_fetch_and_u32(&MyProc->pendingRecoveryConflicts, ~(1 << reason));
@@ -3506,6 +3519,52 @@ ProcessInterrupts(void)
}
}
+ {
+ int handler_count;
+ uint32 weak;
+ uint32 strong;
+
+ handler_count = (int) dbg_sigusr1_conflict_count;
+ weak = pg_atomic_read_u32(&MyProc->pendingRecoveryConflicts);
+
+ /*
+ * Don't pay for a strong read in the common case with no signal and no
+ * pending conflicts.
+ */
+ if (handler_count > 0 || weak != 0)
+ {
+ /*
+ * This handoff is intentionally approximate for diagnostics: a signal
+ * can arrive between reading and clearing this counter.
+ */
+ dbg_sigusr1_conflict_count = 0;
+ strong = pg_atomic_read_membarrier_u32(&MyProc->pendingRecoveryConflicts);
+
+ if (weak != strong)
+ ereport(LOG,
+ (errmsg("DBG ProcessInterrupts[%d] weak/strong mismatch "
+ "weak=0x%x strong=0x%x handler_count=%d",
+ getpid(), weak, strong, handler_count)));
+ else if (handler_count > 0 && weak == 0)
+ ereport(LOG,
+ (errmsg("DBG ProcessInterrupts[%d] handler fired but "
+ "pending=0x0 (spurious wakeup, cleared, or "
+ "counter-race), handler_count=%d",
+ getpid(), handler_count)));
+ else if (handler_count > 0)
+ ereport(LOG,
+ (errmsg("DBG ProcessInterrupts[%d] handler fired "
+ "pending=0x%x handler_count=%d",
+ getpid(), weak, handler_count)));
+ else
+ ereport(LOG,
+ (errmsg("DBG ProcessInterrupts[%d] no handler but "
+ "pending=0x%x (preexisting)",
+ getpid(), weak)));
+ }
+ }
+
+ /* Preserve original dispatch behavior: weak read at point of check. */
if (pg_atomic_read_u32(&MyProc->pendingRecoveryConflicts) != 0)
ProcessRecoveryConflictInterrupts();