Skip to content
Snippets Groups Projects
elog.c 48 KiB
Newer Older
 *
 * This should be called by an error handler after it's done processing
 * the error; or as soon as it's done CopyErrorData, if it intends to
 * do stuff that is likely to provoke another error.  You are not "out" of
 * the error subsystem until you have done this.
 */
void
FlushErrorState(void)
{
	/*
	 * Reset stack to empty.  The only case where it would be more than
	 * one deep is if we serviced an error that interrupted construction
	 * of another message.  We assume control escaped out of that
	 * message construction and won't ever go back.
	 */
	errordata_stack_depth = -1;
	recursion_depth = 0;
	/* Delete all data in ErrorContext */
	MemoryContextResetAndDeleteChildren(ErrorContext);
}

/*
 * ReThrowError --- re-throw a previously copied error
 *
 * A handler can do CopyErrorData/FlushErrorState to get out of the error
 * subsystem, then do some processing, and finally ReThrowError to re-throw
 * the original error.  This is slower than just PG_RE_THROW() but should
 * be used if the "some processing" is likely to incur another error.
 */
void
ReThrowError(ErrorData *edata)
{
	ErrorData  *newedata;

	Assert(edata->elevel == ERROR);

	/* Push the data back into the error context */
	recursion_depth++;
	MemoryContextSwitchTo(ErrorContext);

	if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
	{
		/*
		 * Wups, stack not big enough.  We treat this as a PANIC condition
		 * because it suggests an infinite loop of errors during error
		 * recovery.
		 */
		errordata_stack_depth = -1;	/* make room on stack */
		ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
	}

	newedata = &errordata[errordata_stack_depth];
	memcpy(newedata, edata, sizeof(ErrorData));

	/* Make copies of separately-allocated fields */
	if (newedata->message)
		newedata->message = pstrdup(newedata->message);
	if (newedata->detail)
		newedata->detail = pstrdup(newedata->detail);
	if (newedata->hint)
		newedata->hint = pstrdup(newedata->hint);
	if (newedata->context)
		newedata->context = pstrdup(newedata->context);
	if (newedata->internalquery)
		newedata->internalquery = pstrdup(newedata->internalquery);

	recursion_depth--;
	PG_RE_THROW();
}

/*
 * Initialization of error output file
 */
void
		/*
		 * A debug-output file name was given.
		 *
		 * Make sure we can write the file, and find out if it's a tty.
		 */
		if ((fd = open(OutputFileName, O_CREAT | O_APPEND | O_WRONLY,
					   0666)) < 0)
					(errcode_for_file_access(),
				   errmsg("could not open file \"%s\": %m", OutputFileName)));
		/*
		 * Redirect our stderr to the debug output file.
		 */
		if (!freopen(OutputFileName, "a", stderr))
					(errcode_for_file_access(),
					 errmsg("could not reopen file \"%s\" as stderr: %m",
		/*
		 * If the file is a tty and we're running under the postmaster,
		 * try to send stdout there as well (if it isn't a tty then stderr
		 * will block out stdout, so we may as well let stdout go wherever
		 * it was going before).
		 */
		if (istty && IsUnderPostmaster)
			if (!freopen(OutputFileName, "a", stdout))
						(errcode_for_file_access(),
						 errmsg("could not reopen file \"%s\" as stdout: %m",
#ifdef HAVE_SYSLOG
#define PG_SYSLOG_LIMIT 128
/*
 * Write a message line to syslog if the syslog option is set.
 *
 * Our problem here is that many syslog implementations don't handle
 * long messages in an acceptable manner. While this function doesn't
 * help that fact, it does work around by splitting up messages into
 * smaller pieces.
 */
static void
write_syslog(int level, const char *line)
{
	static bool openlog_done = false;
	static unsigned long seq = 0;
	static int	syslog_fac = LOG_LOCAL0;
	int			len = strlen(line);
		if (pg_strcasecmp(Syslog_facility, "LOCAL0") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL1") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL2") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL3") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL4") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL5") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL6") == 0)
		if (pg_strcasecmp(Syslog_facility, "LOCAL7") == 0)
		openlog(Syslog_ident, LOG_PID | LOG_NDELAY | LOG_NOWAIT, syslog_fac);
		openlog_done = true;
	}

	/*
	 * We add a sequence number to each log message to suppress "same"
	 * messages.
	 */
	seq++;

	/* divide into multiple syslog() calls if message is too long */
	/* or if the message contains embedded NewLine(s) '\n' */
	if (len > PG_SYSLOG_LIMIT || strchr(line, '\n') != NULL)
		int			chunk_nr = 0;
			char		buf[PG_SYSLOG_LIMIT + 1];
			int			buflen;
			int			i;
			/* if we start at a newline, move ahead one char */
			if (line[0] == '\n')
			{
				line++;
				len--;

			strncpy(buf, line, PG_SYSLOG_LIMIT);
			buf[PG_SYSLOG_LIMIT] = '\0';
			if (strchr(buf, '\n') != NULL)
				*strchr(buf, '\n') = '\0';
			/* trim to multibyte letter boundary */
			buflen = pg_mbcliplen(buf, buflen, buflen);
			/* already word boundary? */
			if (!isspace((unsigned char) line[buflen]) &&
				line[buflen] != '\0')
				/* try to divide at word boundary */
				while (i > 0 && !isspace((unsigned char) buf[i]))
				if (i > 0)		/* else couldn't divide word boundary */
				{
					buflen = i;
					buf[i] = '\0';
				}
			}

			chunk_nr++;

			syslog(level, "[%lu-%d] %s", seq, chunk_nr, buf);
			line += buflen;
			len -= buflen;
		}
	}
	else
		syslog(level, "[%lu] %s", seq, line);
#ifdef WIN32
/*
 * Write a message line to the windows event log
 */
static void
write_eventlog(int level, const char *line)
{
	static HANDLE evtHandle = INVALID_HANDLE_VALUE;
	
	if (evtHandle == INVALID_HANDLE_VALUE) {
		evtHandle = RegisterEventSource(NULL,"PostgreSQL");
		if (evtHandle == NULL) {
			evtHandle = INVALID_HANDLE_VALUE;
			return;
		}
	}

	ReportEvent(evtHandle,
				level,
				0,
				0, /* All events are Id 0 */
				NULL,
				1,
				0,
				&line,
				NULL);
}
#endif /* WIN32*/
Bruce Momjian's avatar
Bruce Momjian committed
/*
 * Format tag info for log lines; append to the provided buffer.
Bruce Momjian's avatar
Bruce Momjian committed
 */
static void
log_line_prefix(StringInfo buf)
Bruce Momjian's avatar
Bruce Momjian committed
{
	/* static counter for line numbers */
	static long log_line_number = 0;
	/* has counter been reset in current process? */
	static int	log_my_pid = 0;

	int format_len;
	int i;

	/*
	 * This is one of the few places where we'd rather not inherit a
	 * static variable's value from the postmaster.  But since we will,
	 * reset it when MyProcPid changes.
	 */
	if (log_my_pid != MyProcPid)
	{
		log_line_number = 0;
		log_my_pid = MyProcPid;
	}
	log_line_number++;
Bruce Momjian's avatar
Bruce Momjian committed

	if (Log_line_prefix == NULL)
		return;					/* in case guc hasn't run yet */
Bruce Momjian's avatar
Bruce Momjian committed

	format_len = strlen(Log_line_prefix);
Bruce Momjian's avatar
Bruce Momjian committed

	for (i = 0; i < format_len; i++)
Bruce Momjian's avatar
Bruce Momjian committed
	{
Bruce Momjian's avatar
Bruce Momjian committed
		{
			/* literal char, just copy */
			appendStringInfoChar(buf, Log_line_prefix[i]);
			continue;
		}
		/* go to char after '%' */
		i++;
		if (i >= format_len)
		{
			/* format error - ignore it */
			break;
Bruce Momjian's avatar
Bruce Momjian committed
		}

		/* process the option */
		switch (Log_line_prefix[i])
Bruce Momjian's avatar
Bruce Momjian committed
		{
			case 'u':
				if (MyProcPort)
				{
					const char *username = MyProcPort->user_name;
Bruce Momjian's avatar
Bruce Momjian committed

					if (username == NULL || *username == '\0')
						username = gettext("[unknown]");
					appendStringInfo(buf, "%s", username);
				}
				break;
			case 'd': 
				if (MyProcPort)
				{
					const char *dbname = MyProcPort->database_name;
Bruce Momjian's avatar
Bruce Momjian committed

					if (dbname == NULL || *dbname == '\0')
						dbname = gettext("[unknown]");
					appendStringInfo(buf, "%s", dbname);
				}
				break;
			case 'c':
				if (MyProcPort)
				{
					appendStringInfo(buf, "%lx.%lx",
									 (long)(MyProcPort->session_start.tv_sec),
									 (long)MyProcPid);
				}
				break;
			case 'p':
				appendStringInfo(buf, "%ld", (long)MyProcPid);
				break;
			case 'l':
				appendStringInfo(buf, "%ld", log_line_number);
				break;
			case 't':
				{
					/*
					 * Note: for %t and %s we deliberately use the C library's
					 * strftime/localtime, and not the equivalent functions
					 * from src/timezone.  This ensures that all backends
					 * will report log entries in the same timezone, namely
					 * whatever C-library setting they inherit from the
					 * postmaster.  If we used src/timezone then local
					 * settings of the TimeZone GUC variable would confuse
					 * the log.
					 */
Bruce Momjian's avatar
Bruce Momjian committed

					strftime(strfbuf, sizeof(strfbuf),
							 "%Y-%m-%d %H:%M:%S %Z",
							 localtime(&stamp_time));
					appendStringInfoString(buf, strfbuf);
				}
				break;
			case 's':
				if (MyProcPort)
				{
					time_t stamp_time = MyProcPort->session_start.tv_sec;
					strftime(strfbuf, sizeof(strfbuf),
							 "%Y-%m-%d %H:%M:%S %Z",
							 localtime(&stamp_time));
					appendStringInfoString(buf, strfbuf);
				}
				break;
			case 'i':
				if (MyProcPort)
				{
					appendStringInfo(buf, "%s", MyProcPort->commandTag);
				}
				break;
			case 'r':
				if (MyProcPort)
				{
					appendStringInfo(buf, "%s", MyProcPort->remote_host);
					if (strlen(MyProcPort->remote_port) > 0)
						appendStringInfo(buf, "(%s)",
										 MyProcPort->remote_port);
				}
				break;
			case 'x': 
				/* in postmaster and friends, stop if %x is seen */
				/* in a backend, just ignore */
				if (MyProcPort == NULL)
					i = format_len;
				break;
			case '%': 
				appendStringInfoChar(buf, '%');
				break;
			default:
				/* format error - ignore it */
				break;
Bruce Momjian's avatar
Bruce Momjian committed
		}
	}
}


/*
 * Write error report to server's log
 */
static void
send_message_to_server_log(ErrorData *edata)
Bruce Momjian's avatar
Bruce Momjian committed
	StringInfoData buf;
	log_line_prefix(&buf);
	appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));
	if (Log_error_verbosity >= PGERROR_VERBOSE)
	{
		/* unpack MAKE_SQLSTATE code */
Bruce Momjian's avatar
Bruce Momjian committed
		char		tbuf[12];
		int			ssval;
		int			i;

		ssval = edata->sqlerrcode;
		for (i = 0; i < 5; i++)
		{
			tbuf[i] = PGUNSIXBIT(ssval);
			ssval >>= 6;
		}
		tbuf[i] = '\0';
		appendStringInfo(&buf, "%s: ", tbuf);
	}

		append_with_tabs(&buf, edata->message);
		append_with_tabs(&buf, gettext("missing error text"));
		appendStringInfo(&buf, gettext(" at character %d"),
						 edata->cursorpos);
	else if (edata->internalpos > 0)
		appendStringInfo(&buf, gettext(" at character %d"),
						 edata->internalpos);
	appendStringInfoChar(&buf, '\n');

	if (Log_error_verbosity >= PGERROR_DEFAULT)
	{
		if (edata->detail)
			appendStringInfoString(&buf, gettext("DETAIL:  "));
			append_with_tabs(&buf, edata->detail);
			appendStringInfoChar(&buf, '\n');
		}
			appendStringInfoString(&buf, gettext("HINT:  "));
			append_with_tabs(&buf, edata->hint);
			appendStringInfoChar(&buf, '\n');
		}
		if (edata->internalquery)
		{
			log_line_prefix(&buf);
			appendStringInfoString(&buf, gettext("QUERY:  "));
			append_with_tabs(&buf, edata->internalquery);
			appendStringInfoChar(&buf, '\n');
		}
			appendStringInfoString(&buf, gettext("CONTEXT:  "));
			append_with_tabs(&buf, edata->context);
			appendStringInfoChar(&buf, '\n');
		}
		if (Log_error_verbosity >= PGERROR_VERBOSE)
		{
			/* assume no newlines in funcname or filename... */
			if (edata->funcname && edata->filename)
			{
				log_line_prefix(&buf);
				appendStringInfo(&buf, gettext("LOCATION:  %s, %s:%d\n"),
								 edata->funcname, edata->filename,
								 edata->lineno);
			{
				log_line_prefix(&buf);
				appendStringInfo(&buf, gettext("LOCATION:  %s:%d\n"),
								 edata->filename, edata->lineno);
	 * If the user wants the query that generated this error logged, do it.
	 */
	if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
		appendStringInfoString(&buf, gettext("STATEMENT:  "));
		append_with_tabs(&buf, debug_query_string);
		appendStringInfoChar(&buf, '\n');
	}


#ifdef HAVE_SYSLOG
	/* Write to syslog, if enabled */
	if (Log_destination & LOG_DESTINATION_SYSLOG)
	{
		int			syslog_level;

		switch (edata->elevel)
		{
			case DEBUG5:
			case DEBUG4:
			case DEBUG3:
			case DEBUG2:
			case DEBUG1:
				syslog_level = LOG_DEBUG;
				break;
			case LOG:
			case COMMERROR:
			case INFO:
				syslog_level = LOG_INFO;
				break;
			case NOTICE:
			case WARNING:
				syslog_level = LOG_NOTICE;
				break;
			case ERROR:
				syslog_level = LOG_WARNING;
				break;
			case FATAL:
				syslog_level = LOG_ERR;
				break;
			case PANIC:
			default:
				syslog_level = LOG_CRIT;
				break;
		}

		write_syslog(syslog_level, buf.data);
	}
#endif   /* HAVE_SYSLOG */
#ifdef WIN32
	if (Log_destination & LOG_DESTINATION_EVENTLOG)
	{
		int eventlog_level;
		switch (edata->elevel) 
		{
			case DEBUG5:
			case DEBUG4:
			case DEBUG3:
			case DEBUG2:
			case DEBUG1:
			case LOG:
			case COMMERROR:
			case INFO:
			case NOTICE:
				eventlog_level = EVENTLOG_INFORMATION_TYPE;
				break;
			case WARNING:
				eventlog_level = EVENTLOG_WARNING_TYPE;
				break;
			case ERROR:
			case FATAL:
			case PANIC:
			default:
				eventlog_level = EVENTLOG_ERROR_TYPE;
				break;
		}
		write_eventlog(eventlog_level, buf.data);
	}
#endif   /* WIN32 */
	/* Write to stderr, if enabled */
	if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == Debug)
		fprintf(stderr, "%s", buf.data);
	/* If in the syslogger process, try to write messages direct to file */
	if (am_syslogger)
		write_syslogger_file(buf.data, buf.len);

send_message_to_frontend(ErrorData *edata)
	/* 'N' (Notice) is for nonfatal conditions, 'E' is for errors */
	pq_beginmessage(&msgbuf, (edata->elevel < ERROR) ? 'N' : 'E');

	if (PG_PROTOCOL_MAJOR(FrontendProtocol) >= 3)
	{
		/* New style with separate fields */
Bruce Momjian's avatar
Bruce Momjian committed
		char		tbuf[12];
		int			ssval;
		int			i;
		pq_sendbyte(&msgbuf, PG_DIAG_SEVERITY);
		pq_sendstring(&msgbuf, error_severity(edata->elevel));

		/* unpack MAKE_SQLSTATE code */
		ssval = edata->sqlerrcode;
		for (i = 0; i < 5; i++)
		{
			tbuf[i] = PGUNSIXBIT(ssval);
			ssval >>= 6;
		}
		tbuf[i] = '\0';

		pq_sendbyte(&msgbuf, PG_DIAG_SQLSTATE);
		pq_sendstring(&msgbuf, tbuf);

		/* M field is required per protocol, so always send something */
		pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_PRIMARY);
		if (edata->message)
			pq_sendstring(&msgbuf, edata->message);
		else
			pq_sendstring(&msgbuf, gettext("missing error text"));

		if (edata->detail)
		{
			pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_DETAIL);
			pq_sendstring(&msgbuf, edata->detail);
		}

		if (edata->hint)
		{
			pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_HINT);
			pq_sendstring(&msgbuf, edata->hint);
		}

		if (edata->context)
		{
			pq_sendbyte(&msgbuf, PG_DIAG_CONTEXT);
			pq_sendstring(&msgbuf, edata->context);
		}

		if (edata->cursorpos > 0)
		{
			snprintf(tbuf, sizeof(tbuf), "%d", edata->cursorpos);
			pq_sendbyte(&msgbuf, PG_DIAG_STATEMENT_POSITION);
		if (edata->internalpos > 0)
		{
			snprintf(tbuf, sizeof(tbuf), "%d", edata->internalpos);
			pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_POSITION);
			pq_sendstring(&msgbuf, tbuf);
		}

		if (edata->internalquery)
		{
			pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_QUERY);
			pq_sendstring(&msgbuf, edata->internalquery);
		}

			pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FILE);
			pq_sendstring(&msgbuf, edata->filename);
		}

		if (edata->lineno > 0)
		{
			snprintf(tbuf, sizeof(tbuf), "%d", edata->lineno);
			pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_LINE);
			pq_sendstring(&msgbuf, tbuf);
		}

		if (edata->funcname)
		{
			pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FUNCTION);
			pq_sendstring(&msgbuf, edata->funcname);
		}

Bruce Momjian's avatar
Bruce Momjian committed
		pq_sendbyte(&msgbuf, '\0');		/* terminator */
	}
	else
	{
		/* Old style --- gin up a backwards-compatible message */
		StringInfoData buf;

		initStringInfo(&buf);

		appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));

		if (edata->show_funcname && edata->funcname)
			appendStringInfo(&buf, "%s: ", edata->funcname);

		if (edata->message)
			appendStringInfoString(&buf, edata->message);
		else
			appendStringInfoString(&buf, gettext("missing error text"));

		if (edata->cursorpos > 0)
			appendStringInfo(&buf, gettext(" at character %d"),
							 edata->cursorpos);
		else if (edata->internalpos > 0)
			appendStringInfo(&buf, gettext(" at character %d"),
							 edata->internalpos);

		appendStringInfoChar(&buf, '\n');

		pq_sendstring(&msgbuf, buf.data);

		pfree(buf.data);
	}

	pq_endmessage(&msgbuf);
	 * This flush is normally not necessary, since postgres.c will flush
	 * out waiting data when control returns to the main loop. But it
	 * seems best to leave it here, so that the client has some clue what
	 * happened if the backend dies before getting back to the main loop
	 * ... error/notice messages should not be a performance-critical path
	 * anyway, so an extra flush won't hurt much ...
/*
 * Support routines for formatting error messages.
 */


/*
 * expand_fmt_string --- process special format codes in a format string
 *
 * We must replace %m with the appropriate strerror string, since vsnprintf
 * won't know what to do with it.
 *
 * The result is a palloc'd string.
 */
static char *
expand_fmt_string(const char *fmt, ErrorData *edata)
Bruce Momjian's avatar
Bruce Momjian committed
	StringInfoData buf;
	const char *cp;

	initStringInfo(&buf);

	for (cp = fmt; *cp; cp++)
	{
		if (cp[0] == '%' && cp[1] != '\0')
		{
			cp++;
			if (*cp == 'm')
			{
				/*
Bruce Momjian's avatar
Bruce Momjian committed
				 * Replace %m by system error string.  If there are any
				 * %'s in the string, we'd better double them so that
				 * vsnprintf won't misinterpret.
				 */
				const char *cp2;

				cp2 = useful_strerror(edata->saved_errno);
				for (; *cp2; cp2++)
				{
					if (*cp2 == '%')
						appendStringInfoCharMacro(&buf, '%');
					appendStringInfoCharMacro(&buf, *cp2);
				}
			}
			else
			{
				/* copy % and next char --- this avoids trouble with %%m */
				appendStringInfoCharMacro(&buf, '%');
				appendStringInfoCharMacro(&buf, *cp);
			}
		}
		else
			appendStringInfoCharMacro(&buf, *cp);
	}

	return buf.data;
}


/*
 * A slightly cleaned-up version of strerror()
 */
static const char *
useful_strerror(int errnum)
{
	/* this buffer is only used if errno has a bogus value */
Bruce Momjian's avatar
Bruce Momjian committed
	const char *str;
#ifdef WIN32
	/* Winsock error code range, per WinError.h */
	if (errnum >= 10000 && errnum <= 11999)
		return pgwin32_socket_strerror(errnum);
#endif

	/*
	 * Some strerror()s return an empty string for out-of-range errno.
	 * This is ANSI C spec compliant, but not exactly useful.
	 */
	if (str == NULL || *str == '\0')
	{
		/*
		 * translator: This string will be truncated at 47 characters
		 * expanded.
		 */
		snprintf(errorstr_buf, sizeof(errorstr_buf),
				 gettext("operating system error %d"), errnum);
/*
 * error_severity --- get localized string representing elevel
 */
		case DEBUG1:
		case DEBUG2:
		case DEBUG3:
		case DEBUG4:
		case DEBUG5:
			prefix = gettext("NOTICE");
Bruce Momjian's avatar
Bruce Momjian committed
		case WARNING:
			prefix = gettext("WARNING");
Bruce Momjian's avatar
Bruce Momjian committed
			break;
			prefix = gettext("PANIC");
			break;
		default:
			prefix = "???";
 *	Append the string to the StringInfo buffer, inserting a tab after any
 *	newline.
static void
append_with_tabs(StringInfo buf, const char *str)
	while ((ch = *str++) != '\0')
		appendStringInfoCharMacro(buf, ch);
		if (ch == '\n')
			appendStringInfoCharMacro(buf, '\t');


/* 
 * Write errors to stderr (or by equal means when stderr is
 * not available). Used before ereport/elog can be used
 * safely (memory context, GUC load etc) 
 */
void
write_stderr(const char *fmt,...)
{
	va_list ap;

	fmt = gettext(fmt);

	va_start(ap, fmt);
#ifndef WIN32
	/* On Unix, we just fprintf to stderr */
	vfprintf(stderr, fmt, ap);
#else
	/* On Win32, we print to stderr if running on a console, or write to 
	 * eventlog if running as a service */
	if (pgwin32_is_service()) /* Running as a service */
	{
		char errbuf[2048]; /* Arbitrary size? */

		vsnprintf(errbuf, sizeof(errbuf), fmt, ap);
		
		write_eventlog(EVENTLOG_ERROR_TYPE, errbuf);
	}
	else /* Not running as service, write to stderr */
		vfprintf(stderr, fmt, ap);
#endif
	va_end(ap);
}