Add some debugging details to some of the elog(STOP) conditions for WAL.

Standardize on %X/%X as the formatting for XLOG position display --- we
had a couple of different formats before, and none of 'em were as useful
as hex offsets IMHO.

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 567937ebaeea7112fdd9ea2c3442c2aec6d3381e..df04c0c28335ed90a7ac3fcc8d4ec8b99316643b 100644 (file)
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2001, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $Header: /cvsroot/pgsql/src/backend/access/transam/xlog.c,v 1.75 2001/08/25 18:52:41 tgl Exp $
+ * $Header: /cvsroot/pgsql/src/backend/access/transam/xlog.c,v 1.76 2001/09/06 02:02:48 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -760,7 +760,7 @@ begin:;
        {
                char            buf[8192];
 
-               sprintf(buf, "INSERT @ %u/%u: ", RecPtr.xlogid, RecPtr.xrecoff);
+               sprintf(buf, "INSERT @ %X/%X: ", RecPtr.xlogid, RecPtr.xrecoff);
                xlog_outrec(buf, record);
                if (rdata->data != NULL)
                {
@@ -1012,7 +1012,10 @@ XLogWrite(XLogwrtRqst WriteRqst)
                 * AdvanceXLInsertBuffer.
                 */
                if (!XLByteLT(LogwrtResult.Write, XLogCtl->xlblocks[Write->curridx]))
-                       elog(STOP, "XLogWrite: write request is past end of log");
+                       elog(STOP, "XLogWrite: write request %X/%X is past end of log %X/%X",
+                                LogwrtResult.Write.xlogid, LogwrtResult.Write.xrecoff,
+                                XLogCtl->xlblocks[Write->curridx].xlogid,
+                                XLogCtl->xlblocks[Write->curridx].xrecoff);
 
                /* Advance LogwrtResult.Write to end of current buffer page */
                LogwrtResult.Write = XLogCtl->xlblocks[Write->curridx];
@@ -1190,7 +1193,7 @@ XLogFlush(XLogRecPtr record)
 
        if (XLOG_DEBUG)
        {
-               elog(DEBUG, "XLogFlush%s%s: request %u/%u; write %u/%u; flush %u/%u\n",
+               elog(DEBUG, "XLogFlush%s%s: request %X/%X; write %X/%X; flush %X/%X\n",
                                (IsBootstrapProcessingMode()) ? "(bootstrap)" : "",
                                (InRedo) ? "(redo)" : "",
                                record.xlogid, record.xrecoff,
@@ -1266,7 +1269,9 @@ XLogFlush(XLogRecPtr record)
                        XLogWrite(WriteRqst);
                        S_UNLOCK(&(XLogCtl->logwrt_lck));
                        if (XLByteLT(LogwrtResult.Flush, record))
-                               elog(STOP, "XLogFlush: request is not satisfied");
+                               elog(STOP, "XLogFlush: request %X/%X is not satisfied --- flushed only to %X/%X",
+                                        record.xlogid, record.xrecoff,
+                                        LogwrtResult.Flush.xlogid, LogwrtResult.Flush.xrecoff);
                        break;
                }
                S_LOCK_SLEEP(&(XLogCtl->logwrt_lck), spins++, XLOG_LOCK_TIMEOUT);
@@ -1688,7 +1693,7 @@ RecordIsValid(XLogRecord *record, XLogRecPtr recptr, int emode)
 
        if (!EQ_CRC64(record->xl_crc, crc))
        {
-               elog(emode, "ReadRecord: bad resource manager data checksum in record at %u/%u",
+               elog(emode, "ReadRecord: bad resource manager data checksum in record at %X/%X",
                         recptr.xlogid, recptr.xrecoff);
                return (false);
        }
@@ -1710,7 +1715,7 @@ RecordIsValid(XLogRecord *record, XLogRecPtr recptr, int emode)
 
                if (!EQ_CRC64(cbuf, crc))
                {
-                       elog(emode, "ReadRecord: bad checksum of backup block %d in record at %u/%u",
+                       elog(emode, "ReadRecord: bad checksum of backup block %d in record at %X/%X",
                                 i + 1, recptr.xlogid, recptr.xrecoff);
                        return (false);
                }
@@ -1780,7 +1785,7 @@ ReadRecord(XLogRecPtr *RecPtr, int emode, char *buffer)
                tmpRecPtr.xrecoff += SizeOfXLogPHD;
        }
        else if (!XRecOffIsValid(RecPtr->xrecoff))
-               elog(STOP, "ReadRecord: invalid record offset at (%u, %u)",
+               elog(STOP, "ReadRecord: invalid record offset at %X/%X",
                         RecPtr->xlogid, RecPtr->xrecoff);
 
        if (readFile >= 0 && !XLByteInSeg(*RecPtr, readId, readSeg))
@@ -1819,7 +1824,7 @@ ReadRecord(XLogRecPtr *RecPtr, int emode, char *buffer)
        if ((((XLogPageHeader) readBuf)->xlp_info & XLP_FIRST_IS_CONTRECORD) &&
                RecPtr->xrecoff % BLCKSZ == SizeOfXLogPHD)
        {
-               elog(emode, "ReadRecord: contrecord is requested by (%u, %u)",
+               elog(emode, "ReadRecord: contrecord is requested by %X/%X",
                         RecPtr->xlogid, RecPtr->xrecoff);
                goto next_record_is_invalid;
        }
@@ -1833,7 +1838,7 @@ got_record:;
         */
        if (record->xl_len == 0)
        {
-               elog(emode, "ReadRecord: record with zero length at (%u, %u)",
+               elog(emode, "ReadRecord: record with zero length at %X/%X",
                         RecPtr->xlogid, RecPtr->xrecoff);
                goto next_record_is_invalid;
        }
@@ -1857,13 +1862,13 @@ got_record:;
         */
        if (total_len > _INTL_MAXLOGRECSZ)
        {
-               elog(emode, "ReadRecord: record length %u at (%u, %u) too long",
+               elog(emode, "ReadRecord: record length %u at %X/%X too long",
                         total_len, RecPtr->xlogid, RecPtr->xrecoff);
                goto next_record_is_invalid;
        }
        if (record->xl_rmid > RM_MAX_ID)
        {
-               elog(emode, "ReadRecord: invalid resource manager id %u at (%u, %u)",
+               elog(emode, "ReadRecord: invalid resource manager id %u at %X/%X",
                         record->xl_rmid, RecPtr->xlogid, RecPtr->xrecoff);
                goto next_record_is_invalid;
        }
@@ -1987,7 +1992,7 @@ ValidXLOGHeader(XLogPageHeader hdr, int emode, bool checkSUI)
        recaddr.xrecoff = readSeg * XLogSegSize + readOff;
        if (!XLByteEQ(hdr->xlp_pageaddr, recaddr))
        {
-               elog(emode, "ReadRecord: unexpected pageaddr (%u, %u) in log file %u, segment %u, offset %u",
+               elog(emode, "ReadRecord: unexpected pageaddr %X/%X in log file %u, segment %u, offset %u",
                         hdr->xlp_pageaddr.xlogid, hdr->xlp_pageaddr.xrecoff,
                         readId, readSeg, readOff);
                return false;
@@ -2486,7 +2491,7 @@ StartupXLOG(void)
        if (record != NULL)
        {
                checkPointLoc = ControlFile->checkPoint;
-               elog(LOG, "checkpoint record is at (%u, %u)",
+               elog(LOG, "checkpoint record is at %X/%X",
                         checkPointLoc.xlogid, checkPointLoc.xrecoff);
        }
        else
@@ -2495,7 +2500,7 @@ StartupXLOG(void)
                if (record != NULL)
                {
                        checkPointLoc = ControlFile->prevCheckPoint;
-                       elog(LOG, "using previous checkpoint record at (%u, %u)",
+                       elog(LOG, "using previous checkpoint record at %X/%X",
                                 checkPointLoc.xlogid, checkPointLoc.xrecoff);
                        InRecovery = true;      /* force recovery even if SHUTDOWNED */
                }
@@ -2506,7 +2511,7 @@ StartupXLOG(void)
        memcpy(&checkPoint, XLogRecGetData(record), sizeof(CheckPoint));
        wasShutdown = (record->xl_info == XLOG_CHECKPOINT_SHUTDOWN);
 
-       elog(LOG, "redo record is at (%u, %u); undo record is at (%u, %u); shutdown %s",
+       elog(LOG, "redo record is at %X/%X; undo record is at %X/%X; shutdown %s",
                 checkPoint.redo.xlogid, checkPoint.redo.xrecoff,
                 checkPoint.undo.xlogid, checkPoint.undo.xrecoff,
                 wasShutdown ? "TRUE" : "FALSE");
@@ -2561,7 +2566,7 @@ StartupXLOG(void)
                if (record != NULL)
                {
                        InRedo = true;
-                       elog(LOG, "redo starts at (%u, %u)",
+                       elog(LOG, "redo starts at %X/%X",
                                 ReadRecPtr.xlogid, ReadRecPtr.xrecoff);
                        do
                        {
@@ -2576,7 +2581,7 @@ StartupXLOG(void)
                                {
                                        char            buf[8192];
 
-                                       sprintf(buf, "REDO @ %u/%u; LSN %u/%u: ",
+                                       sprintf(buf, "REDO @ %X/%X; LSN %X/%X: ",
                                                        ReadRecPtr.xlogid, ReadRecPtr.xrecoff,
                                                        EndRecPtr.xlogid, EndRecPtr.xrecoff);
                                        xlog_outrec(buf, record);
@@ -2592,7 +2597,7 @@ StartupXLOG(void)
                                RmgrTable[record->xl_rmid].rm_redo(EndRecPtr, record);
                                record = ReadRecord(NULL, LOG, buffer);
                        } while (record != NULL);
-                       elog(LOG, "redo done at (%u, %u)",
+                       elog(LOG, "redo done at %X/%X",
                                 ReadRecPtr.xlogid, ReadRecPtr.xrecoff);
                        LastRec = ReadRecPtr;
                        InRedo = false;
@@ -2681,7 +2686,7 @@ StartupXLOG(void)
                RecPtr = ReadRecPtr;
                if (XLByteLT(checkPoint.undo, RecPtr))
                {
-                       elog(LOG, "undo starts at (%u, %u)",
+                       elog(LOG, "undo starts at %X/%X",
                                 RecPtr.xlogid, RecPtr.xrecoff);
                        do
                        {
@@ -2691,7 +2696,7 @@ StartupXLOG(void)
                                        RmgrTable[record->xl_rmid].rm_undo(EndRecPtr, record);
                                RecPtr = record->xl_prev;
                        } while (XLByteLE(checkPoint.undo, RecPtr));
-                       elog(LOG, "undo done at (%u, %u)",
+                       elog(LOG, "undo done at %X/%X",
                                 ReadRecPtr.xlogid, ReadRecPtr.xrecoff);
                }
                else
@@ -3144,7 +3149,7 @@ xlog_desc(char *buf, uint8 xl_info, char *rec)
        {
                CheckPoint *checkpoint = (CheckPoint *) rec;
 
-               sprintf(buf + strlen(buf), "checkpoint: redo %u/%u; undo %u/%u; "
+               sprintf(buf + strlen(buf), "checkpoint: redo %X/%X; undo %X/%X; "
                                "sui %u; xid %u; oid %u; %s",
                                checkpoint->redo.xlogid, checkpoint->redo.xrecoff,
                                checkpoint->undo.xlogid, checkpoint->undo.xrecoff,
@@ -3169,7 +3174,7 @@ xlog_outrec(char *buf, XLogRecord *record)
        int                     bkpb;
        int                     i;
 
-       sprintf(buf + strlen(buf), "prev %u/%u; xprev %u/%u; xid %u",
+       sprintf(buf + strlen(buf), "prev %X/%X; xprev %X/%X; xid %u",
                        record->xl_prev.xlogid, record->xl_prev.xrecoff,
                        record->xl_xact_prev.xlogid, record->xl_xact_prev.xrecoff,
                        record->xl_xid);