/*------------------------------------------------------------------------- * * elog.c * error logging and reporting * * Some notes about recursion and errors during error processing: * * We need to be robust about recursive-error scenarios --- for example, * if we run out of memory, it's important to be able to report that fact. * There are a number of considerations that go into this. * * First, distinguish between re-entrant use and actual recursion. It * is possible for an error or warning message to be emitted while the * parameters for an error message are being computed. In this case * errstart has been called for the outer message, and some field values * may have already been saved, but we are not actually recursing. We handle * this by providing a (small) stack of ErrorData records. The inner message * can be computed and sent without disturbing the state of the outer message. * (If the inner message is actually an error, this isn't very interesting * because control won't come back to the outer message generator ... but * if the inner message is only debug or log data, this is critical.) * * Second, actual recursion will occur if an error is reported by one of * the elog.c routines or something they call. By far the most probable * scenario of this sort is "out of memory"; and it's also the nastiest * to handle because we'd likely also run out of memory while trying to * report this error! Our escape hatch for this case is to reset the * ErrorContext to empty before trying to process the inner error. Since * ErrorContext is guaranteed to have at least 8K of space in it (see mcxt.c), * we should be able to process an "out of memory" message successfully. * Since we lose the prior error state due to the reset, we won't be able * to return to processing the original error, but we wouldn't have anyway. * (NOTE: the escape hatch is not used for recursive situations where the * inner message is of less than ERROR severity; in that case we just * try to process it and return normally. Usually this will work, but if * it ends up in infinite recursion, we will PANIC due to error stack * overflow.) * * * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group * Portions Copyright (c) 1994, Regents of the University of California * * * IDENTIFICATION * $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.175 2006/10/01 22:08:18 tgl Exp $ * *------------------------------------------------------------------------- */ #include "postgres.h" #include #include #include #include #include #ifdef HAVE_SYSLOG #include #endif #include "access/transam.h" #include "access/xact.h" #include "libpq/libpq.h" #include "libpq/pqformat.h" #include "mb/pg_wchar.h" #include "miscadmin.h" #include "postmaster/postmaster.h" #include "postmaster/syslogger.h" #include "storage/ipc.h" #include "tcop/tcopprot.h" #include "utils/memutils.h" #include "utils/ps_status.h" /* Global variables */ ErrorContextCallback *error_context_stack = NULL; sigjmp_buf *PG_exception_stack = NULL; /* GUC parameters */ PGErrorVerbosity Log_error_verbosity = PGERROR_VERBOSE; char *Log_line_prefix = NULL; /* format for extra log line info */ int Log_destination = LOG_DESTINATION_STDERR; #ifdef HAVE_SYSLOG static bool openlog_done = false; static char *syslog_ident = NULL; static int syslog_facility = LOG_LOCAL0; static void write_syslog(int level, const char *line); #endif #ifdef WIN32 static void write_eventlog(int level, const char *line); #endif /* We provide a small stack of ErrorData records for re-entrant cases */ #define ERRORDATA_STACK_SIZE 5 static ErrorData errordata[ERRORDATA_STACK_SIZE]; static int errordata_stack_depth = -1; /* index of topmost active frame */ static int recursion_depth = 0; /* to detect actual recursion */ /* Macro for checking errordata_stack_depth is reasonable */ #define CHECK_STACK_DEPTH() \ do { \ if (errordata_stack_depth < 0) \ { \ errordata_stack_depth = -1; \ ereport(ERROR, (errmsg_internal("errstart was not called"))); \ } \ } while (0) static void log_line_prefix(StringInfo buf); static void send_message_to_server_log(ErrorData *edata); static void send_message_to_frontend(ErrorData *edata); static char *expand_fmt_string(const char *fmt, ErrorData *edata); static const char *useful_strerror(int errnum); static const char *error_severity(int elevel); static void append_with_tabs(StringInfo buf, const char *str); /* * errstart --- begin an error-reporting cycle * * Create a stack entry and store the given parameters in it. Subsequently, * errmsg() and perhaps other routines will be called to further populate * the stack entry. Finally, errfinish() will be called to actually process * the error report. * * Returns TRUE in normal case. Returns FALSE to short-circuit the error * report (if it's a warning or lower and not to be reported anywhere). */ bool errstart(int elevel, const char *filename, int lineno, const char *funcname) { ErrorData *edata; bool output_to_server = false; bool output_to_client = false; int i; /* * Check some cases in which we want to promote an error into a more * severe error. None of this logic applies for non-error messages. */ if (elevel >= ERROR) { /* * If we are inside a critical section, all errors become PANIC * errors. See miscadmin.h. */ if (CritSectionCount > 0) elevel = PANIC; /* * Check reasons for treating ERROR as FATAL: * * 1. we have no handler to pass the error to (implies we are in the * postmaster or in backend startup). * * 2. ExitOnAnyError mode switch is set (initdb uses this). * * 3. the error occurred after proc_exit has begun to run. (It's * proc_exit's responsibility to see that this doesn't turn into * infinite recursion!) */ if (elevel == ERROR) { if (PG_exception_stack == NULL || ExitOnAnyError || proc_exit_inprogress) elevel = FATAL; } /* * If the error level is ERROR or more, errfinish is not going to * return to caller; therefore, if there is any stacked error already * in progress it will be lost. This is more or less okay, except we * do not want to have a FATAL or PANIC error downgraded because the * reporting process was interrupted by a lower-grade error. So check * the stack and make sure we panic if panic is warranted. */ for (i = 0; i <= errordata_stack_depth; i++) elevel = Max(elevel, errordata[i].elevel); } /* * Now decide whether we need to process this report at all; if it's * warning or less and not enabled for logging, just return FALSE without * starting up any error logging machinery. */ /* Determine whether message is enabled for server log output */ if (IsPostmasterEnvironment) { /* Complicated because LOG is sorted out-of-order for this purpose */ if (elevel == LOG || elevel == COMMERROR) { if (log_min_messages == LOG) output_to_server = true; else if (log_min_messages < FATAL) output_to_server = true; } else { /* elevel != LOG */ if (log_min_messages == LOG) { if (elevel >= FATAL) output_to_server = true; } /* Neither is LOG */ else if (elevel >= log_min_messages) output_to_server = true; } } else { /* In bootstrap/standalone case, do not sort LOG out-of-order */ output_to_server = (elevel >= log_min_messages); } /* Determine whether message is enabled for client output */ if (whereToSendOutput == DestRemote && elevel != COMMERROR) { /* * client_min_messages is honored only after we complete the * authentication handshake. This is required both for security * reasons and because many clients can't handle NOTICE messages * during authentication. */ if (ClientAuthInProgress) output_to_client = (elevel >= ERROR); else output_to_client = (elevel >= client_min_messages || elevel == INFO); } /* Skip processing effort if non-error message will not be output */ if (elevel < ERROR && !output_to_server && !output_to_client) return false; /* * Okay, crank up a stack entry to store the info in. */ if (recursion_depth++ > 0 && elevel >= ERROR) { /* * Ooops, error during error processing. Clear ErrorContext as * discussed at top of file. We will not return to the original * error's reporter or handler, so we don't need it. */ MemoryContextReset(ErrorContext); /* * If we recurse more than once, the problem might be something broken * in a context traceback routine. Abandon them too. */ if (recursion_depth > 2) error_context_stack = NULL; } 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"))); } /* Initialize data for this error frame */ edata = &errordata[errordata_stack_depth]; MemSet(edata, 0, sizeof(ErrorData)); edata->elevel = elevel; edata->output_to_server = output_to_server; edata->output_to_client = output_to_client; edata->filename = filename; edata->lineno = lineno; edata->funcname = funcname; /* Select default errcode based on elevel */ if (elevel >= ERROR) edata->sqlerrcode = ERRCODE_INTERNAL_ERROR; else if (elevel == WARNING) edata->sqlerrcode = ERRCODE_WARNING; else edata->sqlerrcode = ERRCODE_SUCCESSFUL_COMPLETION; /* errno is saved here so that error parameter eval can't change it */ edata->saved_errno = errno; recursion_depth--; return true; } /* * errfinish --- end an error-reporting cycle * * Produce the appropriate error report(s) and pop the error stack. * * If elevel is ERROR or worse, control does not return to the caller. * See elog.h for the error level definitions. */ void errfinish(int dummy,...) { ErrorData *edata = &errordata[errordata_stack_depth]; int elevel = edata->elevel; MemoryContext oldcontext; ErrorContextCallback *econtext; recursion_depth++; CHECK_STACK_DEPTH(); /* * Do processing in ErrorContext, which we hope has enough reserved space * to report an error. */ oldcontext = MemoryContextSwitchTo(ErrorContext); /* * Call any context callback functions. Errors occurring in callback * functions will be treated as recursive errors --- this ensures we will * avoid infinite recursion (see errstart). */ for (econtext = error_context_stack; econtext != NULL; econtext = econtext->previous) (*econtext->callback) (econtext->arg); /* * If ERROR (not more nor less) we pass it off to the current handler. * Printing it and popping the stack is the responsibility of the handler. */ if (elevel == ERROR) { /* * We do some minimal cleanup before longjmp'ing so that handlers can * execute in a reasonably sane state. */ /* This is just in case the error came while waiting for input */ ImmediateInterruptOK = false; /* * Reset InterruptHoldoffCount in case we ereport'd from inside an * interrupt holdoff section. (We assume here that no handler will * itself be inside a holdoff section. If necessary, such a handler * could save and restore InterruptHoldoffCount for itself, but this * should make life easier for most.) */ InterruptHoldoffCount = 0; CritSectionCount = 0; /* should be unnecessary, but... */ /* * Note that we leave CurrentMemoryContext set to ErrorContext. The * handler should reset it to something else soon. */ recursion_depth--; PG_RE_THROW(); } /* * If we are doing FATAL or PANIC, abort any old-style COPY OUT in * progress, so that we can report the message before dying. (Without * this, pq_putmessage will refuse to send the message at all, which is * what we want for NOTICE messages, but not for fatal exits.) This hack * is necessary because of poor design of old-style copy protocol. Note * we must do this even if client is fool enough to have set * client_min_messages above FATAL, so don't look at output_to_client. */ if (elevel >= FATAL && whereToSendOutput == DestRemote) pq_endcopyout(true); /* Emit the message to the right places */ EmitErrorReport(); /* Now free up subsidiary data attached to stack entry, and release it */ if (edata->message) pfree(edata->message); if (edata->detail) pfree(edata->detail); if (edata->hint) pfree(edata->hint); if (edata->context) pfree(edata->context); if (edata->internalquery) pfree(edata->internalquery); errordata_stack_depth--; /* Exit error-handling context */ MemoryContextSwitchTo(oldcontext); recursion_depth--; /* * Perform error recovery action as specified by elevel. */ if (elevel == FATAL) { /* * For a FATAL error, we let proc_exit clean up and exit. */ ImmediateInterruptOK = false; /* * If we just reported a startup failure, the client will disconnect * on receiving it, so don't send any more to the client. */ if (PG_exception_stack == NULL && whereToSendOutput == DestRemote) whereToSendOutput = DestNone; /* * fflush here is just to improve the odds that we get to see the * error message, in case things are so hosed that proc_exit crashes. * Any other code you might be tempted to add here should probably be * in an on_proc_exit callback instead. */ fflush(stdout); fflush(stderr); /* * If proc_exit is already running, we exit with nonzero exit code to * indicate that something's pretty wrong. We also want to exit with * nonzero exit code if not running under the postmaster (for example, * if we are being run from the initdb script, we'd better return an * error status). */ proc_exit(proc_exit_inprogress || !IsUnderPostmaster); } if (elevel >= PANIC) { /* * Serious crash time. Postmaster will observe nonzero process exit * status and kill the other backends too. * * XXX: what if we are *in* the postmaster? abort() won't kill our * children... */ ImmediateInterruptOK = false; fflush(stdout); fflush(stderr); abort(); } /* * We reach here if elevel <= WARNING. OK to return to caller. * * But check for cancel/die interrupt first --- this is so that the user * can stop a query emitting tons of notice or warning messages, even if * it's in a loop that otherwise fails to check for interrupts. */ CHECK_FOR_INTERRUPTS(); } /* * errcode --- add SQLSTATE error code to the current error * * The code is expected to be represented as per MAKE_SQLSTATE(). */ int errcode(int sqlerrcode) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->sqlerrcode = sqlerrcode; return 0; /* return value does not matter */ } /* * errcode_for_file_access --- add SQLSTATE error code to the current error * * The SQLSTATE code is chosen based on the saved errno value. We assume * that the failing operation was some type of disk file access. * * NOTE: the primary error message string should generally include %m * when this is used. */ int errcode_for_file_access(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); switch (edata->saved_errno) { /* Permission-denied failures */ case EPERM: /* Not super-user */ case EACCES: /* Permission denied */ #ifdef EROFS case EROFS: /* Read only file system */ #endif edata->sqlerrcode = ERRCODE_INSUFFICIENT_PRIVILEGE; break; /* File not found */ case ENOENT: /* No such file or directory */ edata->sqlerrcode = ERRCODE_UNDEFINED_FILE; break; /* Duplicate file */ case EEXIST: /* File exists */ edata->sqlerrcode = ERRCODE_DUPLICATE_FILE; break; /* Wrong object type or state */ case ENOTDIR: /* Not a directory */ case EISDIR: /* Is a directory */ #if defined(ENOTEMPTY) && (ENOTEMPTY != EEXIST) /* same code on AIX */ case ENOTEMPTY: /* Directory not empty */ #endif edata->sqlerrcode = ERRCODE_WRONG_OBJECT_TYPE; break; /* Insufficient resources */ case ENOSPC: /* No space left on device */ edata->sqlerrcode = ERRCODE_DISK_FULL; break; case ENFILE: /* File table overflow */ case EMFILE: /* Too many open files */ edata->sqlerrcode = ERRCODE_INSUFFICIENT_RESOURCES; break; /* Hardware failure */ case EIO: /* I/O error */ edata->sqlerrcode = ERRCODE_IO_ERROR; break; /* All else is classified as internal errors */ default: edata->sqlerrcode = ERRCODE_INTERNAL_ERROR; break; } return 0; /* return value does not matter */ } /* * errcode_for_socket_access --- add SQLSTATE error code to the current error * * The SQLSTATE code is chosen based on the saved errno value. We assume * that the failing operation was some type of socket access. * * NOTE: the primary error message string should generally include %m * when this is used. */ int errcode_for_socket_access(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); switch (edata->saved_errno) { /* Loss of connection */ case EPIPE: #ifdef ECONNRESET case ECONNRESET: #endif edata->sqlerrcode = ERRCODE_CONNECTION_FAILURE; break; /* All else is classified as internal errors */ default: edata->sqlerrcode = ERRCODE_INTERNAL_ERROR; break; } return 0; /* return value does not matter */ } /* * This macro handles expansion of a format string and associated parameters; * it's common code for errmsg(), errdetail(), etc. Must be called inside * a routine that is declared like "const char *fmt, ..." and has an edata * pointer set up. The message is assigned to edata->targetfield, or * appended to it if appendval is true. * * Note: we pstrdup the buffer rather than just transferring its storage * to the edata field because the buffer might be considerably larger than * really necessary. */ #define EVALUATE_MESSAGE(targetfield, appendval) \ { \ char *fmtbuf; \ StringInfoData buf; \ /* Internationalize the error format string */ \ fmt = _(fmt); \ /* Expand %m in format string */ \ fmtbuf = expand_fmt_string(fmt, edata); \ initStringInfo(&buf); \ if ((appendval) && edata->targetfield) \ appendStringInfo(&buf, "%s\n", edata->targetfield); \ /* Generate actual output --- have to use appendStringInfoVA */ \ for (;;) \ { \ va_list args; \ bool success; \ va_start(args, fmt); \ success = appendStringInfoVA(&buf, fmtbuf, args); \ va_end(args); \ if (success) \ break; \ enlargeStringInfo(&buf, buf.maxlen); \ } \ /* Done with expanded fmt */ \ pfree(fmtbuf); \ /* Save the completed message into the stack item */ \ if (edata->targetfield) \ pfree(edata->targetfield); \ edata->targetfield = pstrdup(buf.data); \ pfree(buf.data); \ } /* * errmsg --- add a primary error message text to the current error * * In addition to the usual %-escapes recognized by printf, "%m" in * fmt is replaced by the error message for the caller's value of errno. * * Note: no newline is needed at the end of the fmt string, since * ereport will provide one for the output methods that need it. */ int errmsg(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(message, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errmsg_internal --- add a primary error message text to the current error * * This is exactly like errmsg() except that strings passed to errmsg_internal * are customarily left out of the internationalization message dictionary. * This should be used for "can't happen" cases that are probably not worth * spending translation effort on. */ int errmsg_internal(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(message, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errdetail --- add a detail error message text to the current error */ int errdetail(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(detail, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errhint --- add a hint error message text to the current error */ int errhint(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(hint, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errcontext --- add a context error message text to the current error * * Unlike other cases, multiple calls are allowed to build up a stack of * context information. We assume earlier calls represent more-closely-nested * states. */ int errcontext(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(context, true); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errfunction --- add reporting function name to the current error * * This is used when backwards compatibility demands that the function * name appear in messages sent to old-protocol clients. Note that the * passed string is expected to be a non-freeable constant string. */ int errfunction(const char *funcname) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->funcname = funcname; edata->show_funcname = true; return 0; /* return value does not matter */ } /* * errposition --- add cursor position to the current error */ int errposition(int cursorpos) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->cursorpos = cursorpos; return 0; /* return value does not matter */ } /* * internalerrposition --- add internal cursor position to the current error */ int internalerrposition(int cursorpos) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->internalpos = cursorpos; return 0; /* return value does not matter */ } /* * internalerrquery --- add internal query text to the current error * * Can also pass NULL to drop the internal query text entry. This case * is intended for use in error callback subroutines that are editorializing * on the layout of the error report. */ int internalerrquery(const char *query) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); if (edata->internalquery) { pfree(edata->internalquery); edata->internalquery = NULL; } if (query) edata->internalquery = MemoryContextStrdup(ErrorContext, query); return 0; /* return value does not matter */ } /* * geterrposition --- return the currently set error position (0 if none) * * This is only intended for use in error callback subroutines, since there * is no other place outside elog.c where the concept is meaningful. */ int geterrposition(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); return edata->cursorpos; } /* * getinternalerrposition --- same for internal error position * * This is only intended for use in error callback subroutines, since there * is no other place outside elog.c where the concept is meaningful. */ int getinternalerrposition(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); return edata->internalpos; } /* * elog_start --- startup for old-style API * * All that we do here is stash the hidden filename/lineno/funcname * arguments into a stack entry. * * We need this to be separate from elog_finish because there's no other * portable way to deal with inserting extra arguments into the elog call. * (If macros with variable numbers of arguments were portable, it'd be * easy, but they aren't.) */ void elog_start(const char *filename, int lineno, const char *funcname) { ErrorData *edata; 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"))); } edata = &errordata[errordata_stack_depth]; edata->filename = filename; edata->lineno = lineno; edata->funcname = funcname; /* errno is saved now so that error parameter eval can't change it */ edata->saved_errno = errno; } /* * elog_finish --- finish up for old-style API */ void elog_finish(int elevel, const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; CHECK_STACK_DEPTH(); /* * Do errstart() to see if we actually want to report the message. */ errordata_stack_depth--; errno = edata->saved_errno; if (!errstart(elevel, edata->filename, edata->lineno, edata->funcname)) return; /* nothing to do */ /* * Format error message just like errmsg(). */ recursion_depth++; oldcontext = MemoryContextSwitchTo(ErrorContext); EVALUATE_MESSAGE(message, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; /* * And let errfinish() finish up. */ errfinish(0); } /* * Actual output of the top-of-stack error message * * In the ereport(ERROR) case this is called from PostgresMain (or not at all, * if the error is caught by somebody). For all other severity levels this * is called by errfinish. */ void EmitErrorReport(void) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(ErrorContext); /* Send to server log, if enabled */ if (edata->output_to_server) send_message_to_server_log(edata); /* Send to client, if enabled */ if (edata->output_to_client) send_message_to_frontend(edata); MemoryContextSwitchTo(oldcontext); recursion_depth--; } /* * CopyErrorData --- obtain a copy of the topmost error stack entry * * This is only for use in error handler code. The data is copied into the * current memory context, so callers should always switch away from * ErrorContext first; otherwise it will be lost when FlushErrorState is done. */ ErrorData * CopyErrorData(void) { ErrorData *edata = &errordata[errordata_stack_depth]; ErrorData *newedata; /* * we don't increment recursion_depth because out-of-memory here does not * indicate a problem within the error subsystem. */ CHECK_STACK_DEPTH(); Assert(CurrentMemoryContext != ErrorContext); /* Copy the struct itself */ newedata = (ErrorData *) palloc(sizeof(ErrorData)); 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); return newedata; } /* * FreeErrorData --- free the structure returned by CopyErrorData. * * Error handlers should use this in preference to assuming they know all * the separately-allocated fields. */ void FreeErrorData(ErrorData *edata) { if (edata->message) pfree(edata->message); if (edata->detail) pfree(edata->detail); if (edata->hint) pfree(edata->hint); if (edata->context) pfree(edata->context); if (edata->internalquery) pfree(edata->internalquery); pfree(edata); } /* * FlushErrorState --- flush the error state after error recovery * * 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 DebugFileOpen(void) { int fd, istty; if (OutputFileName[0]) { /* * 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) ereport(FATAL, (errcode_for_file_access(), errmsg("could not open file \"%s\": %m", OutputFileName))); istty = isatty(fd); close(fd); /* * Redirect our stderr to the debug output file. */ if (!freopen(OutputFileName, "a", stderr)) ereport(FATAL, (errcode_for_file_access(), errmsg("could not reopen file \"%s\" as stderr: %m", OutputFileName))); /* * 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)) ereport(FATAL, (errcode_for_file_access(), errmsg("could not reopen file \"%s\" as stdout: %m", OutputFileName))); } } #ifdef HAVE_SYSLOG /* * Set or update the parameters for syslog logging */ void set_syslog_parameters(const char *ident, int facility) { /* * guc.c is likely to call us repeatedly with same parameters, so don't * thrash the syslog connection unnecessarily. Also, we do not re-open * the connection until needed, since this routine will get called whether * or not Log_destination actually mentions syslog. * * Note that we make our own copy of the ident string rather than relying * on guc.c's. This may be overly paranoid, but it ensures that we cannot * accidentally free a string that syslog is still using. */ if (syslog_ident == NULL || strcmp(syslog_ident, ident) != 0 || syslog_facility != facility) { if (openlog_done) { closelog(); openlog_done = false; } if (syslog_ident) free(syslog_ident); syslog_ident = strdup(ident); /* if the strdup fails, we will cope in write_syslog() */ syslog_facility = facility; } } #ifndef PG_SYSLOG_LIMIT #define PG_SYSLOG_LIMIT 128 #endif /* * Write a message line to syslog */ static void write_syslog(int level, const char *line) { static unsigned long seq = 0; int len; /* Open syslog connection if not done yet */ if (!openlog_done) { openlog(syslog_ident ? syslog_ident : "postgres", LOG_PID | LOG_NDELAY | LOG_NOWAIT, syslog_facility); openlog_done = true; } /* * We add a sequence number to each log message to suppress "same" * messages. */ seq++; /* * 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. * * We divide into multiple syslog() calls if message is too long or if the * message contains embedded NewLine(s) '\n'. */ len = strlen(line); if (len > PG_SYSLOG_LIMIT || strchr(line, '\n') != NULL) { int chunk_nr = 0; while (len > 0) { char buf[PG_SYSLOG_LIMIT + 1]; const char *nlpos; int buflen; int i; /* if we start at a newline, move ahead one char */ if (line[0] == '\n') { line++; len--; continue; } /* copy one line, or as much as will fit, to buf */ nlpos = strchr(line, '\n'); if (nlpos != NULL) buflen = nlpos - line; else buflen = len; buflen = Min(buflen, PG_SYSLOG_LIMIT); memcpy(buf, line, buflen); buf[buflen] = '\0'; /* trim to multibyte letter boundary */ buflen = pg_mbcliplen(buf, buflen, buflen); if (buflen <= 0) return; buf[buflen] = '\0'; /* already word boundary? */ if (line[buflen] != '\0' && !isspace((unsigned char) line[buflen])) { /* try to divide at word boundary */ i = buflen - 1; while (i > 0 && !isspace((unsigned char) buf[i])) 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 { /* message short enough */ syslog(level, "[%lu] %s", seq, line); } } #endif /* HAVE_SYSLOG */ #ifdef WIN32 /* * Write a message line to the windows event log */ static void write_eventlog(int level, const char *line) { int eventlevel = EVENTLOG_ERROR_TYPE; static HANDLE evtHandle = INVALID_HANDLE_VALUE; if (evtHandle == INVALID_HANDLE_VALUE) { evtHandle = RegisterEventSource(NULL, "PostgreSQL"); if (evtHandle == NULL) { evtHandle = INVALID_HANDLE_VALUE; return; } } switch (level) { case DEBUG5: case DEBUG4: case DEBUG3: case DEBUG2: case DEBUG1: case LOG: case COMMERROR: case INFO: case NOTICE: eventlevel = EVENTLOG_INFORMATION_TYPE; break; case WARNING: eventlevel = EVENTLOG_WARNING_TYPE; break; case ERROR: case FATAL: case PANIC: default: eventlevel = EVENTLOG_ERROR_TYPE; break; } ReportEvent(evtHandle, eventlevel, 0, 0, /* All events are Id 0 */ NULL, 1, 0, &line, NULL); } #endif /* WIN32 */ /* * Format tag info for log lines; append to the provided buffer. */ static void log_line_prefix(StringInfo buf) { /* 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++; if (Log_line_prefix == NULL) return; /* in case guc hasn't run yet */ format_len = strlen(Log_line_prefix); for (i = 0; i < format_len; i++) { if (Log_line_prefix[i] != '%') { /* literal char, just copy */ appendStringInfoChar(buf, Log_line_prefix[i]); continue; } /* go to char after '%' */ i++; if (i >= format_len) break; /* format error - ignore it */ /* process the option */ switch (Log_line_prefix[i]) { case 'u': if (MyProcPort) { const char *username = MyProcPort->user_name; if (username == NULL || *username == '\0') username = _("[unknown]"); appendStringInfo(buf, "%s", username); } break; case 'd': if (MyProcPort) { const char *dbname = MyProcPort->database_name; if (dbname == NULL || *dbname == '\0') dbname = _("[unknown]"); appendStringInfo(buf, "%s", dbname); } break; case 'c': if (MyProcPort) { appendStringInfo(buf, "%lx.%x", (long) (MyProcPort->session_start), MyProcPid); } break; case 'p': appendStringInfo(buf, "%d", MyProcPid); break; case 'l': appendStringInfo(buf, "%ld", log_line_number); break; case 'm': { /* * Note: for %m, %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. */ time_t stamp_time; char strfbuf[128], msbuf[8]; struct timeval tv; gettimeofday(&tv, NULL); stamp_time = tv.tv_sec; strftime(strfbuf, sizeof(strfbuf), /* leave room for milliseconds... */ /* Win32 timezone names are too long so don't print them */ #ifndef WIN32 "%Y-%m-%d %H:%M:%S %Z", #else "%Y-%m-%d %H:%M:%S ", #endif localtime(&stamp_time)); /* 'paste' milliseconds into place... */ sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000)); strncpy(strfbuf + 19, msbuf, 4); appendStringInfoString(buf, strfbuf); } break; case 't': { time_t stamp_time = time(NULL); char strfbuf[128]; strftime(strfbuf, sizeof(strfbuf), /* Win32 timezone names are too long so don't print them. */ #ifndef WIN32 "%Y-%m-%d %H:%M:%S %Z", #else "%Y-%m-%d %H:%M:%S", #endif localtime(&stamp_time)); appendStringInfoString(buf, strfbuf); } break; case 's': if (MyProcPort) { char strfbuf[128]; strftime(strfbuf, sizeof(strfbuf), "%Y-%m-%d %H:%M:%S %Z", localtime(&MyProcPort->session_start)); appendStringInfoString(buf, strfbuf); } break; case 'i': if (MyProcPort) { const char *psdisp; int displen; psdisp = get_ps_display(&displen); appendStringInfo(buf, "%.*s", displen, psdisp); } break; case 'r': if (MyProcPort && MyProcPort->remote_host) { appendStringInfo(buf, "%s", MyProcPort->remote_host); if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0') appendStringInfo(buf, "(%s)", MyProcPort->remote_port); } break; case 'h': if (MyProcPort && MyProcPort->remote_host) appendStringInfo(buf, "%s", MyProcPort->remote_host); break; case 'q': /* in postmaster and friends, stop if %q is seen */ /* in a backend, just ignore */ if (MyProcPort == NULL) i = format_len; break; case 'x': if (MyProcPort) { if (IsTransactionState()) appendStringInfo(buf, "%u", GetTopTransactionId()); else appendStringInfo(buf, "%u", InvalidTransactionId); } break; case '%': appendStringInfoChar(buf, '%'); break; default: /* format error - ignore it */ break; } } } /* * Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a * static buffer. */ char * unpack_sql_state(int sql_state) { static char buf[12]; int i; for (i = 0; i < 5; i++) { buf[i] = PGUNSIXBIT(sql_state); sql_state >>= 6; } buf[i] = '\0'; return buf; } /* * Write error report to server's log */ static void send_message_to_server_log(ErrorData *edata) { StringInfoData buf; initStringInfo(&buf); log_line_prefix(&buf); appendStringInfo(&buf, "%s: ", error_severity(edata->elevel)); if (Log_error_verbosity >= PGERROR_VERBOSE) appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode)); if (edata->message) append_with_tabs(&buf, edata->message); else append_with_tabs(&buf, _("missing error text")); if (edata->cursorpos > 0) appendStringInfo(&buf, _(" at character %d"), edata->cursorpos); else if (edata->internalpos > 0) appendStringInfo(&buf, _(" at character %d"), edata->internalpos); appendStringInfoChar(&buf, '\n'); if (Log_error_verbosity >= PGERROR_DEFAULT) { if (edata->detail) { log_line_prefix(&buf); appendStringInfoString(&buf, _("DETAIL: ")); append_with_tabs(&buf, edata->detail); appendStringInfoChar(&buf, '\n'); } if (edata->hint) { log_line_prefix(&buf); appendStringInfoString(&buf, _("HINT: ")); append_with_tabs(&buf, edata->hint); appendStringInfoChar(&buf, '\n'); } if (edata->internalquery) { log_line_prefix(&buf); appendStringInfoString(&buf, _("QUERY: ")); append_with_tabs(&buf, edata->internalquery); appendStringInfoChar(&buf, '\n'); } if (edata->context) { log_line_prefix(&buf); appendStringInfoString(&buf, _("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, _("LOCATION: %s, %s:%d\n"), edata->funcname, edata->filename, edata->lineno); } else if (edata->filename) { log_line_prefix(&buf); appendStringInfo(&buf, _("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) { log_line_prefix(&buf); appendStringInfoString(&buf, _("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 /* Write to eventlog, if enabled */ if (Log_destination & LOG_DESTINATION_EVENTLOG) { write_eventlog(edata->elevel, buf.data); } #endif /* WIN32 */ /* Write to stderr, if enabled */ if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug) { #ifdef WIN32 /* * In a win32 service environment, there is no usable stderr. Capture * anything going there and write it to the eventlog instead. * * If stderr redirection is active, it's ok to write to stderr because * that's really a pipe to the syslogger process. */ if ((!Redirect_stderr || am_syslogger) && pgwin32_is_service()) write_eventlog(edata->elevel, buf.data); else #endif 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); pfree(buf.data); } /* * Write error report to client */ static void send_message_to_frontend(ErrorData *edata) { StringInfoData msgbuf; /* '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 */ 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, _("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); pq_sendstring(&msgbuf, tbuf); } 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); } if (edata->filename) { 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); } 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, _("missing error text")); if (edata->cursorpos > 0) appendStringInfo(&buf, _(" at character %d"), edata->cursorpos); else if (edata->internalpos > 0) appendStringInfo(&buf, _(" 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 ... */ pq_flush(); } /* * 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) { StringInfoData buf; const char *cp; initStringInfo(&buf); for (cp = fmt; *cp; cp++) { if (cp[0] == '%' && cp[1] != '\0') { cp++; if (*cp == 'm') { /* * 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 */ static char errorstr_buf[48]; const char *str; #ifdef WIN32 /* Winsock error code range, per WinError.h */ if (errnum >= 10000 && errnum <= 11999) return pgwin32_socket_strerror(errnum); #endif str = strerror(errnum); /* * 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), _("operating system error %d"), errnum); str = errorstr_buf; } return str; } /* * error_severity --- get localized string representing elevel */ static const char * error_severity(int elevel) { const char *prefix; switch (elevel) { case DEBUG1: case DEBUG2: case DEBUG3: case DEBUG4: case DEBUG5: prefix = _("DEBUG"); break; case LOG: case COMMERROR: prefix = _("LOG"); break; case INFO: prefix = _("INFO"); break; case NOTICE: prefix = _("NOTICE"); break; case WARNING: prefix = _("WARNING"); break; case ERROR: prefix = _("ERROR"); break; case FATAL: prefix = _("FATAL"); break; case PANIC: prefix = _("PANIC"); break; default: prefix = "???"; break; } return prefix; } /* * append_with_tabs * * Append the string to the StringInfo buffer, inserting a tab after any * newline. */ static void append_with_tabs(StringInfo buf, const char *str) { char ch; 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 = _(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); }