Arrange to emit a description of the current XLOG record as error context

when an error occurs during xlog replay.  Also, replace the former risky
'write into a fixed-size buffer with no overflow detection' API for XLOG
record description routines; use an expansible StringInfo instead.  (The
latter accounts for most of the patch bulk.)

Qingqing Zhou

src/backend/access/transam/clog.c

@@ -24,7 +24,7 @@
  * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/clog.c,v 1.37 2006/03/05 15:58:21 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/clog.c,v 1.38 2006/03/24 04:32:12 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -412,17 +412,17 @@ clog_redo(XLogRecPtr lsn, XLogRecord *record)
 }
 
 void
-clog_desc(char *buf, uint8 xl_info, char *rec)
+clog_desc(StringInfo buf, uint8 xl_info, char *rec)
 {
-	uint8		info = xl_info & ~XLR_INFO_MASK;
+	uint8			info = xl_info & ~XLR_INFO_MASK;
 
 	if (info == CLOG_ZEROPAGE)
 	{
 		int			pageno;
 
 		memcpy(&pageno, rec, sizeof(int));
-		sprintf(buf + strlen(buf), "zeropage: %d", pageno);
+		appendStringInfo(buf, "zeropage: %d", pageno);
 	}
 	else
-		strcat(buf, "UNKNOWN");
+		appendStringInfo(buf, "UNKNOWN");
 }

src/backend/access/transam/multixact.c

@@ -42,7 +42,7 @@
  * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/multixact.c,v 1.16 2006/03/05 15:58:21 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/multixact.c,v 1.17 2006/03/24 04:32:12 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -1887,7 +1887,7 @@ multixact_redo(XLogRecPtr lsn, XLogRecord *record)
 }
 
 void
-multixact_desc(char *buf, uint8 xl_info, char *rec)
+multixact_desc(StringInfo buf, uint8 xl_info, char *rec)
 {
 	uint8		info = xl_info & ~XLR_INFO_MASK;
 
@@ -1896,25 +1896,25 @@ multixact_desc(char *buf, uint8 xl_info, char *rec)
 		int			pageno;
 
 		memcpy(&pageno, rec, sizeof(int));
-		sprintf(buf + strlen(buf), "zero offsets page: %d", pageno);
+		appendStringInfo(buf, "zero offsets page: %d", pageno);
 	}
 	else if (info == XLOG_MULTIXACT_ZERO_MEM_PAGE)
 	{
 		int			pageno;
 
 		memcpy(&pageno, rec, sizeof(int));
-		sprintf(buf + strlen(buf), "zero members page: %d", pageno);
+		appendStringInfo(buf, "zero members page: %d", pageno);
 	}
 	else if (info == XLOG_MULTIXACT_CREATE_ID)
 	{
 		xl_multixact_create *xlrec = (xl_multixact_create *) rec;
 		int			i;
 
-		sprintf(buf + strlen(buf), "create multixact %u offset %u:",
+		appendStringInfo(buf, "create multixact %u offset %u:",
 				xlrec->mid, xlrec->moff);
 		for (i = 0; i < xlrec->nxids; i++)
-			sprintf(buf + strlen(buf), " %u", xlrec->xids[i]);
+			appendStringInfo(buf, " %u", xlrec->xids[i]);
 	}
 	else
-		strcat(buf, "UNKNOWN");
+		appendStringInfo(buf, "UNKNOWN");
 }

src/backend/access/transam/xact.c

@@ -10,7 +10,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/access/transam/xact.c,v 1.217 2006/03/05 15:58:22 momjian Exp $
+ *	  $PostgreSQL: pgsql/src/backend/access/transam/xact.c,v 1.218 2006/03/24 04:32:12 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -4179,22 +4179,22 @@ xact_redo(XLogRecPtr lsn, XLogRecord *record)
 }
 
 static void
-xact_desc_commit(char *buf, xl_xact_commit *xlrec)
+xact_desc_commit(StringInfo buf, xl_xact_commit *xlrec)
 {
 	struct tm  *tm = localtime(&xlrec->xtime);
 	int			i;
 
-	sprintf(buf + strlen(buf), "%04u-%02u-%02u %02u:%02u:%02u",
+	appendStringInfo(buf, "%04u-%02u-%02u %02u:%02u:%02u",
 			tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday,
 			tm->tm_hour, tm->tm_min, tm->tm_sec);
 	if (xlrec->nrels > 0)
 	{
-		sprintf(buf + strlen(buf), "; rels:");
+		appendStringInfo(buf, "; rels:");
 		for (i = 0; i < xlrec->nrels; i++)
 		{
 			RelFileNode rnode = xlrec->xnodes[i];
 
-			sprintf(buf + strlen(buf), " %u/%u/%u",
+			appendStringInfo(buf, " %u/%u/%u",
 					rnode.spcNode, rnode.dbNode, rnode.relNode);
 		}
 	}
@@ -4203,29 +4203,29 @@ xact_desc_commit(char *buf, xl_xact_commit *xlrec)
 		TransactionId *xacts = (TransactionId *)
 		&xlrec->xnodes[xlrec->nrels];
 
-		sprintf(buf + strlen(buf), "; subxacts:");
+		appendStringInfo(buf, "; subxacts:");
 		for (i = 0; i < xlrec->nsubxacts; i++)
-			sprintf(buf + strlen(buf), " %u", xacts[i]);
+			appendStringInfo(buf, " %u", xacts[i]);
 	}
 }
 
 static void
-xact_desc_abort(char *buf, xl_xact_abort *xlrec)
+xact_desc_abort(StringInfo buf, xl_xact_abort *xlrec)
 {
 	struct tm  *tm = localtime(&xlrec->xtime);
 	int			i;
 
-	sprintf(buf + strlen(buf), "%04u-%02u-%02u %02u:%02u:%02u",
+	appendStringInfo(buf, "%04u-%02u-%02u %02u:%02u:%02u",
 			tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday,
 			tm->tm_hour, tm->tm_min, tm->tm_sec);
 	if (xlrec->nrels > 0)
 	{
-		sprintf(buf + strlen(buf), "; rels:");
+		appendStringInfo(buf, "; rels:");
 		for (i = 0; i < xlrec->nrels; i++)
 		{
 			RelFileNode rnode = xlrec->xnodes[i];
 
-			sprintf(buf + strlen(buf), " %u/%u/%u",
+			appendStringInfo(buf, " %u/%u/%u",
 					rnode.spcNode, rnode.dbNode, rnode.relNode);
 		}
 	}
@@ -4234,49 +4234,49 @@ xact_desc_abort(char *buf, xl_xact_abort *xlrec)
 		TransactionId *xacts = (TransactionId *)
 		&xlrec->xnodes[xlrec->nrels];
 
-		sprintf(buf + strlen(buf), "; subxacts:");
+		appendStringInfo(buf, "; subxacts:");
 		for (i = 0; i < xlrec->nsubxacts; i++)
-			sprintf(buf + strlen(buf), " %u", xacts[i]);
+			appendStringInfo(buf, " %u", xacts[i]);
 	}
 }
 
 void
-xact_desc(char *buf, uint8 xl_info, char *rec)
+xact_desc(StringInfo buf, uint8 xl_info, char *rec)
 {
-	uint8		info = xl_info & ~XLR_INFO_MASK;
+	uint8			info = xl_info & ~XLR_INFO_MASK;
 
 	if (info == XLOG_XACT_COMMIT)
 	{
 		xl_xact_commit *xlrec = (xl_xact_commit *) rec;
 
-		strcat(buf, "commit: ");
+		appendStringInfo(buf, "commit: ");
 		xact_desc_commit(buf, xlrec);
 	}
 	else if (info == XLOG_XACT_ABORT)
 	{
 		xl_xact_abort *xlrec = (xl_xact_abort *) rec;
 
-		strcat(buf, "abort: ");
+		appendStringInfo(buf, "abort: ");
 		xact_desc_abort(buf, xlrec);
 	}
 	else if (info == XLOG_XACT_PREPARE)
 	{
-		strcat(buf, "prepare");
+		appendStringInfo(buf, "prepare");
 	}
 	else if (info == XLOG_XACT_COMMIT_PREPARED)
 	{
 		xl_xact_commit_prepared *xlrec = (xl_xact_commit_prepared *) rec;
 
-		sprintf(buf + strlen(buf), "commit %u: ", xlrec->xid);
+		appendStringInfo(buf, "commit %u: ", xlrec->xid);
 		xact_desc_commit(buf, &xlrec->crec);
 	}
 	else if (info == XLOG_XACT_ABORT_PREPARED)
 	{
 		xl_xact_abort_prepared *xlrec = (xl_xact_abort_prepared *) rec;
 
-		sprintf(buf + strlen(buf), "abort %u: ", xlrec->xid);
+		appendStringInfo(buf, "abort %u: ", xlrec->xid);
 		xact_desc_abort(buf, &xlrec->arec);
 	}
 	else
-		strcat(buf, "UNKNOWN");
+		appendStringInfo(buf, "UNKNOWN");
 }

src/backend/access/transam/xlog.c

@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/xlog.c,v 1.227 2006/03/05 15:58:22 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/xlog.c,v 1.228 2006/03/24 04:32:13 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -498,10 +498,11 @@ static char *str_time(time_t tnow);
 static void issue_xlog_fsync(void);
 
 #ifdef WAL_DEBUG
-static void xlog_outrec(char *buf, XLogRecord *record);
+static void xlog_outrec(StringInfo buf, XLogRecord *record);
 #endif
 static bool read_backup_label(XLogRecPtr *checkPointLoc);
 static void remove_backup_label(void);
+static void rm_redo_error_callback(void *arg);
 
 
 /*
@@ -852,16 +853,19 @@ begin:;
 #ifdef WAL_DEBUG
 	if (XLOG_DEBUG)
 	{
-		char		buf[8192];
+		StringInfoData	buf;
 
-		sprintf(buf, "INSERT @ %X/%X: ", RecPtr.xlogid, RecPtr.xrecoff);
-		xlog_outrec(buf, record);
+		initStringInfo(&buf);
+		appendStringInfo(&buf, "INSERT @ %X/%X: ", 
+							RecPtr.xlogid, RecPtr.xrecoff);
+		xlog_outrec(&buf, record);
 		if (rdata->data != NULL)
 		{
-			strcat(buf, " - ");
-			RmgrTable[record->xl_rmid].rm_desc(buf, record->xl_info, rdata->data);
+			appendStringInfo(&buf, " - ");
+			RmgrTable[record->xl_rmid].rm_desc(&buf, record->xl_info, rdata->data);
 		}
-		elog(LOG, "%s", buf);
+		elog(LOG, "%s", buf.data);
+		pfree(buf.data);
 	}
 #endif
 
@@ -4562,6 +4566,7 @@ StartupXLOG(void)
 		{
 			bool		recoveryContinue = true;
 			bool		recoveryApply = true;
+			ErrorContextCallback	errcontext;
 
 			InRedo = true;
 			ereport(LOG,
@@ -4576,16 +4581,19 @@ StartupXLOG(void)
 #ifdef WAL_DEBUG
 				if (XLOG_DEBUG)
 				{
-					char		buf[8192];
+					StringInfoData	buf;
 
-					sprintf(buf, "REDO @ %X/%X; LSN %X/%X: ",
+					initStringInfo(&buf);
+					appendStringInfo(&buf, "REDO @ %X/%X; LSN %X/%X: ",
 							ReadRecPtr.xlogid, ReadRecPtr.xrecoff,
 							EndRecPtr.xlogid, EndRecPtr.xrecoff);
-					xlog_outrec(buf, record);
-					strcat(buf, " - ");
-					RmgrTable[record->xl_rmid].rm_desc(buf,
-									record->xl_info, XLogRecGetData(record));
-					elog(LOG, "%s", buf);
+					xlog_outrec(&buf, record);
+					appendStringInfo(&buf, " - ");
+					RmgrTable[record->xl_rmid].rm_desc(&buf,
+													   record->xl_info,
+													   XLogRecGetData(record));
+					elog(LOG, "%s", buf.data);
+					pfree(buf.data);
 				}
 #endif
 
@@ -4600,6 +4608,12 @@ StartupXLOG(void)
 						break;
 				}
 
+				/* Setup error traceback support for ereport() */
+				errcontext.callback = rm_redo_error_callback;
+				errcontext.arg = (void *) record;
+				errcontext.previous = error_context_stack;
+				error_context_stack = &errcontext;
+
 				/* nextXid must be beyond record's xid */
 				if (TransactionIdFollowsOrEquals(record->xl_xid,
 												 ShmemVariableCache->nextXid))
@@ -4613,6 +4627,9 @@ StartupXLOG(void)
 
 				RmgrTable[record->xl_rmid].rm_redo(EndRecPtr, record);
 
+				/* Pop the error context stack */
+				error_context_stack = errcontext.previous;
+
 				LastRec = ReadRecPtr;
 
 				record = ReadRecord(NULL, LOG);
@@ -5400,16 +5417,16 @@ xlog_redo(XLogRecPtr lsn, XLogRecord *record)
 }
 
 void
-xlog_desc(char *buf, uint8 xl_info, char *rec)
+xlog_desc(StringInfo buf, uint8 xl_info, char *rec)
 {
-	uint8		info = xl_info & ~XLR_INFO_MASK;
+	uint8			info = xl_info & ~XLR_INFO_MASK;
 
 	if (info == XLOG_CHECKPOINT_SHUTDOWN ||
 		info == XLOG_CHECKPOINT_ONLINE)
 	{
 		CheckPoint *checkpoint = (CheckPoint *) rec;
 
-		sprintf(buf + strlen(buf), "checkpoint: redo %X/%X; undo %X/%X; "
+		appendStringInfo(buf, "checkpoint: redo %X/%X; undo %X/%X; "
 				"tli %u; xid %u; oid %u; multi %u; offset %u; %s",
 				checkpoint->redo.xlogid, checkpoint->redo.xrecoff,
 				checkpoint->undo.xlogid, checkpoint->undo.xrecoff,
@@ -5424,21 +5441,21 @@ xlog_desc(char *buf, uint8 xl_info, char *rec)
 		Oid			nextOid;
 
 		memcpy(&nextOid, rec, sizeof(Oid));
-		sprintf(buf + strlen(buf), "nextOid: %u", nextOid);
+		appendStringInfo(buf, "nextOid: %u", nextOid);
 	}
 	else
-		strcat(buf, "UNKNOWN");
+		appendStringInfo(buf, "UNKNOWN");
 }
 
 #ifdef WAL_DEBUG
 
 static void
-xlog_outrec(char *buf, XLogRecord *record)
+xlog_outrec(StringInfo buf, XLogRecord *record)
 {
 	int			bkpb;
 	int			i;
 
-	sprintf(buf + strlen(buf), "prev %X/%X; xid %u",
+	appendStringInfo(buf, "prev %X/%X; xid %u",
 			record->xl_prev.xlogid, record->xl_prev.xrecoff,
 			record->xl_xid);
 
@@ -5450,9 +5467,9 @@ xlog_outrec(char *buf, XLogRecord *record)
 	}
 
 	if (bkpb)
-		sprintf(buf + strlen(buf), "; bkpb %d", bkpb);
+		appendStringInfo(buf, "; bkpb %d", bkpb);
 
-	sprintf(buf + strlen(buf), ": %s",
+	appendStringInfo(buf, ": %s",
 			RmgrTable[record->xl_rmid].rm_name);
 }
 #endif   /* WAL_DEBUG */
@@ -5976,3 +5993,24 @@ remove_backup_label(void)
 					 errmsg("could not remove file \"%s\": %m",
 							BACKUP_LABEL_FILE)));
 }
+
+/*
+ * Error context callback for errors occurring during rm_redo().
+ */
+static void
+rm_redo_error_callback(void *arg)
+{
+	XLogRecord		*record = (XLogRecord *) arg;
+	StringInfoData	 buf;
+
+	initStringInfo(&buf);
+	RmgrTable[record->xl_rmid].rm_desc(&buf, 
+									   record->xl_info, 
+									   XLogRecGetData(record));
+
+	/* don't bother emitting empty description */
+	if (buf.len > 0)
+		errcontext("xlog redo %s", buf.data);
+
+	pfree(buf.data);
+}