/*------------------------------------------------------------------------- * * elog.c * error logging and reporting * * Because of the extremely high rate at which log messages can be generated, * we need to be mindful of the performance cost of obtaining any information * that may be logged. Also, it's important to keep in mind that this code may * get called from within an aborted transaction, in which case operations * such as syscache lookups are unsafe. * * 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) 2003-2023, PgPool Global Development Group * Portions Copyright (c) 1996-2015, PostgreSQL Global Development Group * Portions Copyright (c) 1994, Regents of the University of California * * * IDENTIFICATION * src/utils/error/elog.c * *------------------------------------------------------------------------- */ #include "pool.h" #include "pool_type.h" #include "utils/palloc.h" #include #include #include #include #include #include #ifdef HAVE_SYSLOG #include #endif #include #include #include #include #include "main/pgpool_logger.h" #include "utils/elog.h" #include "utils/memutils.h" #include "pool_config.h" #include "utils/pool_stream.h" #include "context/pool_session_context.h" #include "pool.h" #define MAX_ON_EXITS 64 static struct ONEXIT { void (*function) (int code, Datum arg); Datum arg; } on_proc_exit_list[MAX_ON_EXITS], on_shmem_exit_list[MAX_ON_EXITS]; static int on_proc_exit_index, on_shmem_exit_index; struct ONEXIT on_exit_prepare = {NULL, 0L}; /* * This flag tracks whether we've called atexit() in the current process * (or in the parent postmaster). */ static bool atexit_callback_setup = false; /* * This flag is set during proc_exit() to change ereport()'s behavior, * so that an ereport() from an on_proc_exit routine cannot get us out * of the exit procedure. We do NOT want to go back to the idle loop... */ bool proc_exit_inprogress = false; /* local functions */ static void proc_exit_prepare(int code); /* Note: whereToSendOutput is initialized for the bootstrap/standalone case */ CommandDest whereToSendOutput = DestDebug; char OutputFileName[1024]; /* debugging output file */ /* Global variables */ ErrorContextCallback *error_context_stack = NULL; sigjmp_buf *PG_exception_stack = NULL; /* * Hook for intercepting messages before they are sent to the server log. * Note that the hook will not get called for messages that are suppressed * by log_min_messages. Also note that logging hooks implemented in preload * libraries will miss any log messages that are generated before the * library is loaded. */ emit_log_hook_type emit_log_hook = NULL; #ifdef HAVE_SYSLOG /* * Max string length to send to syslog(). Note that this doesn't count the * sequence-number prefix we add, and of course it doesn't count the prefix * added by syslog itself. Solaris and sysklogd truncate the final message * at 1024 bytes, so this value leaves 124 bytes for those prefixes. (Most * other syslog implementations seem to have limits of 2KB or so.) */ #ifndef PG_SYSLOG_LIMIT #define PG_SYSLOG_LIMIT 900 #endif 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 static void send_message_to_server_log(ErrorData *edata); static void send_message_to_frontend(ErrorData *edata); static void write_pipe_chunks(char *data, int len, int dest); static void write_console(const char *line, int len); static void log_line_prefix(StringInfo buf, const char *line_prefix, ErrorData *edata); static const char *process_log_prefix_padding(const char *p, int *ppadding); #ifdef WIN32 extern char *event_source; static void write_eventlog(int level, const char *line, int len); #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 */ static int frontend_error_recursion_depth = 0; /* to detect recursion in * delivering error to * frontend clients */ /* 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 char *expand_fmt_string(const char *fmt, ErrorData *edata); static const char *useful_strerror(int errnum); static const char *error_severity(int elevel, bool for_frontend); static const char *process_name(void); static void append_with_tabs(StringInfo buf, const char *str); static bool is_log_level_output(int elevel, int log_min_level); static inline bool should_output_to_server(int elevel); static inline bool should_output_to_client(int elevel); /* * is_log_level_output -- is elevel logically >= log_min_level? * * We use this for tests that should consider LOG to sort out-of-order, * between ERROR and FATAL. Generally this is the right thing for testing * whether a message should go to the pgpool log, whereas a simple >= * test is correct for testing whether the message should go to the client. */ static bool is_log_level_output(int elevel, int log_min_level) { if (elevel == LOG || elevel == COMMERROR || elevel == FRONTEND_ONLY_ERROR || elevel == FRONTEND_LOG) { if (log_min_level == LOG || log_min_level <= ERROR) return true; } else if (elevel == FRONTEND_DEBUG) { if (log_min_level <= DEBUG1) return true; } else if (log_min_level == LOG) { /* elevel != LOG */ if (elevel >= FATAL) return true; } /* Neither is LOG */ else if (elevel >= log_min_level) return true; return false; } /* * should_output_to_server --- should message of given elevel go to the log? */ static inline bool should_output_to_server(int elevel) { return is_log_level_output(elevel, pool_config->log_min_messages); } /* * should_output_to_client --- should message of given elevel go to the client? */ static inline bool should_output_to_client(int elevel) { /* Determine whether message is enabled for client output */ if (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. */ return (elevel >= pool_config->client_min_messages || elevel == INFO || elevel == FRONTEND_ONLY_ERROR); } return false; } /* * message_level_is_interesting --- would ereport/elog do anything? * * Returns true if ereport/elog with this elevel will not be a no-op. * This is useful to short-circuit any expensive preparatory work that * might be needed for a logging message. There is no point in * prepending this to a bare ereport/elog call, however. */ bool message_level_is_interesting(int elevel) { /* * Keep this in sync with the decision-making in errstart(). */ if (elevel >= ERROR || should_output_to_server(elevel) || should_output_to_client(elevel)) return true; return false; } /* * in_error_recursion_trouble --- are we at risk of infinite error recursion? * * This function exists to provide common control of various fallback steps * that we take if we think we are facing infinite error recursion. See the * callers for details. */ bool in_error_recursion_trouble(void) { /* Pull the plug if recurse more than once */ return (recursion_depth > 2); } /* * 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, const char *domain) { ErrorData *edata; bool output_to_server; bool output_to_client = false; int i; int frontend_invalid = false; /* * 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 == FRONTEND_ERROR) { frontend_invalid = true; elevel = ERROR; } else if (elevel == FRONTEND_DEBUG || elevel == FRONTEND_LOG) { frontend_invalid = true; } if (elevel >= ERROR && elevel != FRONTEND_ONLY_ERROR) { /* * 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 || elevel == FRONTEND_LOG || elevel == FRONTEND_DEBUG) { if (PG_exception_stack == NULL || 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 */ output_to_server = should_output_to_server(elevel); output_to_client = should_output_to_client(elevel); /* 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 && elevel != FRONTEND_ONLY_ERROR) { /* * Oops, 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); /* * Infinite error recursion might be due to something broken in a * context traceback routine. Abandon them too. We also abandon * attempting to print the error statement (which, if long, could * itself be the source of the recursive failure). */ if (in_error_recursion_trouble()) { error_context_stack = NULL; output_to_client = false; } } 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->frontend_invalid = frontend_invalid; edata->output_to_server = output_to_server; edata->output_to_client = output_to_client; if (elevel == FATAL && PG_exception_stack == NULL) /* This is startup * failure. Take down * main process with it */ edata->retcode = POOL_EXIT_FATAL; else edata->retcode = POOL_EXIT_AND_RESTART; if (filename) { const char *slash; /* keep only base name, useful especially for vpath builds */ slash = strrchr(filename, '/'); if (slash) filename = slash + 1; } edata->filename = filename; edata->lineno = lineno; edata->funcname = funcname; /* the default text domain is the backend's */ edata->domain = domain ? domain : PG_TEXTDOMAIN("pgpool"); edata->saved_errno = errno; /* * Any allocations for this error state level should go into ErrorContext */ edata->assoc_context = ErrorContext; 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; int retcode = edata->retcode; 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 || elevel == FRONTEND_LOG || elevel == FRONTEND_DEBUG) { /* * We do some minimal cleanup before longjmp'ing so that handlers can * execute in a reasonably sane state. */ /* * 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. */ /* 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->detail_log) pfree(edata->detail_log); if (edata->hint) pfree(edata->hint); if (edata->context) pfree(edata->context); if (edata->schema_name) pfree(edata->schema_name); if (edata->table_name) pfree(edata->table_name); if (edata->column_name) pfree(edata->column_name); if (edata->datatype_name) pfree(edata->datatype_name); if (edata->constraint_name) pfree(edata->constraint_name); 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) { /* * 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 or on_shmem_exit callback instead. */ fflush(stdout); fflush(stderr); /* * Do normal process-exit cleanup, then return exit code 1 to indicate * FATAL termination. The postmaster may or may not consider this * worthy of panic, depending on which subprocess returns it. */ proc_exit(retcode); } if (elevel >= PANIC && elevel != FRONTEND_ONLY_ERROR) { /* * Serious crash time. Postmaster will observe SIGABRT process exit * status and kill the other backends too. * * XXX: what if we are *in* the postmaster? abort() won't kill our * children... */ 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. */ } /* * errcode --- add SQLSTATE error code to the current error * * The code is expected to be represented as per MAKE_SQLSTATE(). */ int errcode_ign(int sqlerrcode) { return 0; /* return value does not matter */ } int pool_error_code(const char *errcode) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); edata->pgpool_errcode = pstrdup(errcode); MemoryContextSwitchTo(oldcontext); recursion_depth--; 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. The message is subject to translation * if translateit 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(domain, targetfield, appendval, translateit) \ { \ char *fmtbuf; \ StringInfoData buf; \ /* Internationalize the error format string */ \ if (translateit && !in_error_recursion_trouble()) \ fmt = dgettext((domain), fmt); \ /* Expand %m in format string */ \ fmtbuf = expand_fmt_string(fmt, edata); \ initStringInfo(&buf); \ if ((appendval) && edata->targetfield) { \ appendStringInfoString(&buf, edata->targetfield); \ appendStringInfoChar(&buf, '\n'); \ } \ /* Generate actual output --- have to use appendStringInfoVA */ \ for (;;) \ { \ va_list args; \ int needed; \ va_start(args, fmt); \ needed = appendStringInfoVA(&buf, fmtbuf, args); \ va_end(args); \ if (needed == 0) \ break; \ enlargeStringInfo(&buf, needed); \ } \ /* 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); \ } /* * Same as above, except for pluralized error messages. The calling routine * must be declared like "const char *fmt_singular, const char *fmt_plural, * unsigned long n, ...". Translation is assumed always wanted. */ #define EVALUATE_MESSAGE_PLURAL(domain, targetfield, appendval) \ { \ const char *fmt; \ char *fmtbuf; \ StringInfoData buf; \ /* Internationalize the error format string */ \ if (!in_error_recursion_trouble()) \ fmt = dngettext((domain), fmt_singular, fmt_plural, n); \ else \ fmt = (n == 1 ? fmt_singular : fmt_plural); \ /* Expand %m in format string */ \ fmtbuf = expand_fmt_string(fmt, edata); \ initStringInfo(&buf); \ if ((appendval) && edata->targetfield) { \ appendStringInfoString(&buf, edata->targetfield); \ appendStringInfoChar(&buf, '\n'); \ } \ /* Generate actual output --- have to use appendStringInfoVA */ \ for (;;) \ { \ va_list args; \ int needed; \ va_start(args, n); \ needed = appendStringInfoVA(&buf, fmtbuf, args); \ va_end(args); \ if (needed == 0) \ break; \ enlargeStringInfo(&buf, needed); \ } \ /* 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(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, message, false, true); 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 not translated, and 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. * We also use this for certain cases where we *must* not try to translate * the message because the translation would fail and result in infinite * error recursion. */ int errmsg_internal(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, message, false, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errmsg_plural --- add a primary error message text to the current error, * with support for pluralization of the message text */ int errmsg_plural(const char *fmt_singular, const char *fmt_plural, unsigned long n,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE_PLURAL(edata->domain, 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(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, detail, false, true); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errdetail_internal --- add a detail error message text to the current error * * This is exactly like errdetail() except that strings passed to * errdetail_internal are not translated, and are customarily left out of the * internationalization message dictionary. This should be used for detail * messages that seem not worth translating for one reason or another * (typically, that they don't seem to be useful to average users). */ int errdetail_internal(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, detail, false, false); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errdetail_log --- add a detail_log error message text to the current error */ int errdetail_log(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, detail_log, false, true); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errdetail_plural --- add a detail error message text to the current error, * with support for pluralization of the message text */ int errdetail_plural(const char *fmt_singular, const char *fmt_plural, unsigned long n,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE_PLURAL(edata->domain, 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(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, hint, false, true); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * errcontext_msg --- 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_msg(const char *fmt,...) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE(edata->context_domain, context, true, true); MemoryContextSwitchTo(oldcontext); recursion_depth--; return 0; /* return value does not matter */ } /* * set_errcontext_domain --- set message domain to be used by errcontext() * * errcontext_msg() can be called from a different module than the original * ereport(), so we cannot use the message domain passed in errstart() to * translate it. Instead, each errcontext_msg() call should be preceded by * a set_errcontext_domain() call to specify the domain. This is usually * done transparently by the errcontext() macro. */ int set_errcontext_domain(const char *domain) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->context_domain = domain; return 0; /* return value does not matter */ } /* * errhidestmt --- optionally suppress STATEMENT: field of log entry * * This should be called if the message text already includes the statement. */ int errhidestmt(bool hide_stmt) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->hide_stmt = hide_stmt; 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 */ } int return_code(int retcode) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); edata->retcode = retcode; return retcode; /* return value does not matter */ } int get_return_code(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); return edata->retcode; } /* * geterrcode --- return the currently set SQLSTATE error code * * 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 geterrcode(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); return edata->sqlerrcode; } /* * getfrontendinvalid --- return the currently frontend_invalid value * * This is only intended for use in error callback subroutines, since there * is no other place outside elog.c where the concept is meaningful. */ bool getfrontendinvalid(void) { ErrorData *edata = &errordata[errordata_stack_depth]; /* we don't bother incrementing recursion_depth */ CHECK_STACK_DEPTH(); return edata->frontend_invalid; } /* * 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; } /* * elog_start --- startup for old-style API * * All that we do here is stash the hidden filename/lineno/funcname * arguments into a stack entry, along with the current value of errno. * * We need this to be separate from elog_finish because there's no other * C89-compliant way to deal with inserting extra arguments into the elog * call. (When using C99's __VA_ARGS__, we could possibly merge this with * elog_finish, but there doesn't seem to be a good way to save errno before * evaluating the format arguments if we do that.) */ 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. Note that the message is intentionally not localized, * else failure to convert it to client encoding could cause further * recursion. */ errordata_stack_depth = -1; /* make room on stack */ ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded"))); } edata = &errordata[errordata_stack_depth]; if (filename) { const char *slash; /* keep only base name, useful especially for vpath builds */ slash = strrchr(filename, '/'); if (slash) filename = slash + 1; } 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; /* Use ErrorContext for any allocations done at this level. */ edata->assoc_context = ErrorContext; } /* * 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, NULL)) return; /* nothing to do */ /* * Format error message just like errmsg_internal(). */ recursion_depth++; oldcontext = MemoryContextSwitchTo(edata->assoc_context); EVALUATE_MESSAGE(edata->domain, message, false, 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(edata->assoc_context); /* * Call hook before sending message to log. The hook function is allowed * to turn off edata->output_to_server, so we must recheck that afterward. * Making any other change in the content of edata is not considered * supported. * * Note: the reason why the hook can only turn off output_to_server, and * not turn it on, is that it'd be unreliable: we will never get here at * all if errstart() deems the message uninteresting. A hook that could * make decisions in that direction would have to hook into errstart(), * where it would have much less information available. emit_log_hook is * intended for custom log filtering and custom log message transmission * mechanisms. */ if (edata->output_to_server && emit_log_hook) (*emit_log_hook) (edata); /* 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->detail_log) newedata->detail_log = pstrdup(newedata->detail_log); if (newedata->hint) newedata->hint = pstrdup(newedata->hint); if (newedata->context) newedata->context = pstrdup(newedata->context); if (newedata->schema_name) newedata->schema_name = pstrdup(newedata->schema_name); if (newedata->table_name) newedata->table_name = pstrdup(newedata->table_name); if (newedata->column_name) newedata->column_name = pstrdup(newedata->column_name); if (newedata->datatype_name) newedata->datatype_name = pstrdup(newedata->datatype_name); if (newedata->constraint_name) newedata->constraint_name = pstrdup(newedata->constraint_name); if (newedata->internalquery) newedata->internalquery = pstrdup(newedata->internalquery); /* Use the calling context for string allocation */ newedata->assoc_context = CurrentMemoryContext; 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->detail_log) pfree(edata->detail_log); if (edata->hint) pfree(edata->hint); if (edata->context) pfree(edata->context); if (edata->schema_name) pfree(edata->schema_name); if (edata->table_name) pfree(edata->table_name); if (edata->column_name) pfree(edata->column_name); if (edata->datatype_name) pfree(edata->datatype_name); if (edata->constraint_name) pfree(edata->constraint_name); 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; frontend_error_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->detail_log) newedata->detail_log = pstrdup(newedata->detail_log); if (newedata->hint) newedata->hint = pstrdup(newedata->hint); if (newedata->context) newedata->context = pstrdup(newedata->context); if (newedata->schema_name) newedata->schema_name = pstrdup(newedata->schema_name); if (newedata->table_name) newedata->table_name = pstrdup(newedata->table_name); if (newedata->column_name) newedata->column_name = pstrdup(newedata->column_name); if (newedata->datatype_name) newedata->datatype_name = pstrdup(newedata->datatype_name); if (newedata->constraint_name) newedata->constraint_name = pstrdup(newedata->constraint_name); if (newedata->internalquery) newedata->internalquery = pstrdup(newedata->internalquery); /* Reset the assoc_context to be ErrorContext */ newedata->assoc_context = ErrorContext; recursion_depth--; PG_RE_THROW(); } /* * pg_re_throw --- out-of-line implementation of PG_RE_THROW() macro */ void pg_re_throw(void) { /* If possible, throw the error to the next outer setjmp handler */ if (PG_exception_stack != NULL) siglongjmp(*PG_exception_stack, 1); else { /* * If we get here, elog(ERROR) was thrown inside a PG_TRY block, which * we have now exited only to discover that there is no outer setjmp * handler to pass the error to. Had the error been thrown outside * the block to begin with, we'd have promoted the error to FATAL, so * the correct behavior is to make it FATAL now; that is, emit it and * then call proc_exit. */ ErrorData *edata = &errordata[errordata_stack_depth]; Assert(errordata_stack_depth >= 0); Assert(edata->elevel == ERROR); edata->elevel = FATAL; edata->output_to_server = should_output_to_server(FATAL); edata->output_to_client = should_output_to_client(FATAL); /* * We can use errfinish() for the rest, but we don't want it to call * any error context routines a second time. Since we know we are * about to exit, it should be OK to just clear the context stack. */ error_context_stack = NULL; errfinish(0); } /* Doesn't return ... */ ExceptionalCondition("pg_re_throw tried to return", "FailedAssertion", __FILE__, __LINE__); } /* * GetErrorContextStack - Return the context stack, for display/diags * * Returns a pstrdup'd string in the caller's context which includes the PG * error call stack. It is the caller's responsibility to ensure this string * is pfree'd (or its context cleaned up) when done. * * This information is collected by traversing the error contexts and calling * each context's callback function, each of which is expected to call * errcontext() to return a string which can be presented to the user. */ char * GetErrorContextStack(void) { ErrorData *edata; ErrorContextCallback *econtext; /* * Okay, crank up a stack entry to store the info in. */ recursion_depth++; 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"))); } /* * Things look good so far, so initialize our error frame */ edata = &errordata[errordata_stack_depth]; MemSet(edata, 0, sizeof(ErrorData)); /* * Set up assoc_context to be the caller's context, so any allocations * done (which will include edata->context) will use their context. */ edata->assoc_context = CurrentMemoryContext; /* * Call any context callback functions to collect the context information * into edata->context. * * Errors occurring in callback functions should go through the regular * error handling code which should handle any recursive errors, though we * double-check above, just in case. */ for (econtext = error_context_stack; econtext != NULL; econtext = econtext->previous) (*econtext->callback) (econtext->arg); /* * Clean ourselves off the stack, any allocations done should have been * using edata->assoc_context, which we set up earlier to be the caller's * context, so we're free to just remove our entry off the stack and * decrement recursion depth and exit. */ errordata_stack_depth--; recursion_depth--; /* * Return a pointer to the string the caller asked for, which should have * been allocated in their context. */ return edata->context; } #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; } } /* * Write a message line to syslog */ static void write_syslog(int level, const char *line) { static unsigned long seq = 0; int len; const char *nlpos; /* Open syslog connection if not done yet */ if (!openlog_done) { openlog(pool_config->syslog_ident ? pool_config->syslog_ident : "pgpool", LOG_PID | LOG_NDELAY | LOG_NOWAIT, pool_config->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). */ len = strlen(line); nlpos = strchr(line, '\n'); if (len > PG_SYSLOG_LIMIT || nlpos != NULL) { int chunk_nr = 0; while (len > 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--; /* we need to recompute the next newline's position, too */ nlpos = strchr(line, '\n'); continue; } /* copy one line, or as much as will fit, to buf */ 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 /* * Get the PostgreSQL equivalent of the Windows ANSI code page. "ANSI" system * interfaces (e.g. CreateFileA()) expect string arguments in this encoding. * Every process in a given system will find the same value at all times. */ static int GetACPEncoding(void) { static int encoding = -2; if (encoding == -2) encoding = pg_codepage_to_encoding(GetACP()); return encoding; } /* * Write a message line to the windows event log */ static void write_eventlog(int level, const char *line, int len) { WCHAR *utf16; int eventlevel = EVENTLOG_ERROR_TYPE; static HANDLE evtHandle = INVALID_HANDLE_VALUE; if (evtHandle == INVALID_HANDLE_VALUE) { evtHandle = RegisterEventSource(NULL, event_source ? event_source : "pgpool"); 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 FRONTEND_LOG: case FRONTEND_DEBUG: 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; } /* * If message character encoding matches the encoding expected by * ReportEventA(), call it to avoid the hazards of conversion. Otherwise, * try to convert the message to UTF16 and write it with ReportEventW(). * Fall back on ReportEventA() if conversion failed. * * Also verify that we are not on our way into error recursion trouble due * to error messages thrown deep inside pgwin32_message_to_UTF16(). */ if (!in_error_recursion_trouble() && GetMessageEncoding() != GetACPEncoding()) { utf16 = pgwin32_message_to_UTF16(line, len, NULL); if (utf16) { ReportEventW(evtHandle, eventlevel, 0, 0, /* All events are Id 0 */ NULL, 1, 0, (LPCWSTR *) & utf16, NULL); /* XXX Try ReportEventA() when ReportEventW() fails? */ pfree(utf16); return; } } ReportEventA(evtHandle, eventlevel, 0, 0, /* All events are Id 0 */ NULL, 1, 0, &line, NULL); } #endif /* WIN32 */ static void write_console(const char *line, int len) { int rc; #ifdef WIN32 /* * Try to convert the message to UTF16 and write it with WriteConsoleW(). * Fall back on write() if anything fails. * * In contrast to write_eventlog(), don't skip straight to write() based * on the applicable encodings. Unlike WriteConsoleW(), write() depends * on the suitability of the console output code page. Since we put * stderr into binary mode in SubPostmasterMain(), write() skips the * necessary translation anyway. * * WriteConsoleW() will fail if stderr is redirected, so just fall through * to writing unconverted to the logfile in this case. * * Since we palloc the structure required for conversion, also fall * through to writing unconverted if we have not yet set up * CurrentMemoryContext. */ if (!in_error_recursion_trouble() && !redirection_done && CurrentMemoryContext != NULL) { WCHAR *utf16; int utf16len; utf16 = pgwin32_message_to_UTF16(line, len, &utf16len); if (utf16 != NULL) { HANDLE stdHandle; DWORD written; stdHandle = GetStdHandle(STD_ERROR_HANDLE); if (WriteConsoleW(stdHandle, utf16, utf16len, &written, NULL)) { pfree(utf16); return; } /* * In case WriteConsoleW() failed, fall back to writing the * message unconverted. */ pfree(utf16); } } #else /* * Conversion on non-win32 platforms is not implemented yet. It requires * non-throw version of pg_do_encoding_conversion(), that converts * unconvertible characters to '?' without errors. */ #endif /* * We ignore any error from write() here. We have no useful way to report * it ... certainly whining on stderr isn't likely to be productive. */ rc = write(fileno(stderr), line, len); (void) rc; } /* * Send data to the syslogger using the chunked protocol * * Note: when there are multiple backends writing into the syslogger pipe, * it's critical that each write go into the pipe indivisibly, and not * get interleaved with data from other processes. Fortunately, the POSIX * spec requires that writes to pipes be atomic so long as they are not * more than PIPE_BUF bytes long. So we divide long messages into chunks * that are no more than that length, and send one chunk per write() call. * The collector process knows how to reassemble the chunks. * * Because of the atomic write requirement, there are only two possible * results from write() here: -1 for failure, or the requested number of * bytes. There is not really anything we can do about a failure; retry would * probably be an infinite loop, and we can't even report the error usefully. * (There is noplace else we could send it!) So we might as well just ignore * the result from write(). However, on some platforms you get a compiler * warning from ignoring write()'s result, so do a little dance with casting * rc to void to shut up the compiler. */ static void write_pipe_chunks(char *data, int len, int dest) { PipeProtoChunk p; int fd = fileno(stderr); int rc; Assert(len > 0); p.proto.nuls[0] = p.proto.nuls[1] = '\0'; p.proto.pid = myProcPid; /* write all but the last chunk */ while (len > PIPE_MAX_PAYLOAD) { p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'F' : 'f'); p.proto.len = PIPE_MAX_PAYLOAD; memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD); rc = write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD); (void) rc; data += PIPE_MAX_PAYLOAD; len -= PIPE_MAX_PAYLOAD; } /* write the last chunk */ p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'T' : 't'); p.proto.len = len; memcpy(p.proto.data, data, len); rc = write(fd, &p, PIPE_HEADER_SIZE + len); (void) rc; } /* * Write error report to frontend log */ static void send_message_to_frontend(ErrorData *edata) { int protoVersion = PROTO_MAJOR_V3; /* default protocol version is * V3 also used by pcp lib */ if (pool_frontend_exists() < 0) return; /* * Leave if we are failing on sending the message to frontend. */ if (++frontend_error_recursion_depth > 2) return; if (processType == PT_CHILD) { /* * Do not forward the debug messages to client before session is * initialized */ if (edata->elevel < ERROR && pool_get_session_context(true) == NULL) { frontend_error_recursion_depth--; return; } protoVersion = get_frontend_protocol_version(); set_pg_frontend_blocking(false); } if (protoVersion == PROTO_MAJOR_V2) { char *message = edata->message ? edata->message : "missing error text"; pool_send_to_frontend((edata->elevel < ERROR) ? "N" : "E", 1, false); pool_send_to_frontend(message, strlen(message), false); pool_send_to_frontend("\n", 1, true); } else if (protoVersion == PROTO_MAJOR_V3) { /* * Buffer length for each message part */ #define MAXMSGBUF 256 /* * Buffer length for result message buffer. Since msg is consisted of * 7 parts, msg buffer should be large enough to hold those message * parts */ #define MAXDATA (MAXMSGBUF+1)*7+1 char data[MAXDATA]; char msgbuf[MAXMSGBUF + 1]; int len; int thislen; int sendlen; len = 0; memset(data, 0, MAXDATA); pool_send_to_frontend((edata->elevel < ERROR) ? "N" : "E", 1, false); /* error level */ thislen = snprintf(msgbuf, MAXMSGBUF, "S%s", error_severity(edata->elevel, true)); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; /* code */ thislen = snprintf(msgbuf, MAXMSGBUF, "C%s", edata->pgpool_errcode ? edata->pgpool_errcode : "XX000"); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; /* message */ thislen = snprintf(msgbuf, MAXMSGBUF, "M%s", edata->message ? edata->message : "missing error text"); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; /* detail */ if (edata->detail) { thislen = snprintf(msgbuf, MAXMSGBUF, "D%s", edata->detail); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; } /* hint */ if (edata->hint) { thislen = snprintf(msgbuf, MAXMSGBUF, "H%s", edata->hint); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; } /* file */ thislen = snprintf(msgbuf, MAXMSGBUF, "F%s", edata->filename); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; /* line */ thislen = snprintf(msgbuf, MAXMSGBUF, "L%d", edata->lineno); thislen = Min(thislen, MAXMSGBUF); memcpy(data + len, msgbuf, thislen + 1); len += thislen + 1; /* stop null */ len++; *(data + len - 1) = '\0'; sendlen = len; len = htonl(len + 4); pool_send_to_frontend((char *) &len, sizeof(len), false); pool_send_to_frontend(data, sendlen, true); } if (edata->elevel == FRONTEND_ONLY_ERROR) { /* * send the ready for query to complete the frontend error cycle */ /* ready for query */ pool_send_to_frontend((char *) "Z", 1, true); if (protoVersion == PROTO_MAJOR_V3) { int len = htonl(5); pool_send_to_frontend((char *) &len, sizeof(len), false); pool_send_to_frontend((char *) "I", 1, true); } } if (processType == PT_CHILD) set_pg_frontend_blocking(true); frontend_error_recursion_depth--; } /* * process_log_prefix_padding --- helper function for processing the format * string in log_line_prefix * * Note: This function returns NULL if it finds something which * it deems invalid in the format string. */ static const char * process_log_prefix_padding(const char *p, int *ppadding) { int paddingsign = 1; int padding = 0; if (*p == '-') { p++; if (*p == '\0') /* Did the buf end in %- ? */ return NULL; paddingsign = -1; } /* generate an int version of the numerical string */ while (*p >= '0' && *p <= '9') padding = padding * 10 + (*p++ - '0'); /* format is invalid if it ends with the padding number */ if (*p == '\0') return NULL; padding *= paddingsign; *ppadding = padding; return p; } /* * Format tag info for log lines; append to the provided buffer. */ static void log_line_prefix(StringInfo buf, const char *line_prefix, ErrorData *edata) { /* 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 padding; const char *p; POOL_CONNECTION *frontend = NULL; POOL_SESSION_CONTEXT *session = pool_get_session_context(true); char strbuf[129]; if (session) frontend = session->frontend; /* * 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. MyStartTime also changes when MyProcPid does, so * reset the formatted start timestamp too. */ if (log_my_pid != myProcPid) { log_line_number = 0; log_my_pid = myProcPid; } log_line_number++; if (line_prefix == NULL) return; /* in case guc hasn't run yet */ for (p = line_prefix; *p != '\0'; p++) { if (*p != '%') { /* literal char, just copy */ appendStringInfoChar(buf, *p); continue; } /* must be a '%', so skip to the next char */ p++; if (*p == '\0') break; /* format error - ignore it */ else if (*p == '%') { /* string contains %% */ appendStringInfoChar(buf, '%'); continue; } /* * Process any formatting which may exist after the '%'. Note that * process_log_prefix_padding moves p past the padding number if it * exists. * * Note: Since only '-', '0' to '9' are valid formatting characters we * can do a quick check here to pre-check for formatting. If the char * is not formatting then we can skip a useless function call. * * Further note: At least on some platforms, passing %*s rather than * %s to appendStringInfo() is substantially slower, so many of the * cases below avoid doing that unless non-zero padding is in fact * specified. */ if (*p > '9') padding = 0; else if ((p = process_log_prefix_padding(p, &padding)) == NULL) break; /* process the option */ switch (*p) { case 'a': /* application name */ { char *appname; appname = get_application_name(); if (appname == NULL || *appname == '\0') appname = "[unknown]"; if (padding != 0) appendStringInfo(buf, "%*s", padding, appname); else appendStringInfoString(buf, appname); } break; case 'P': /* process name */ { if (padding != 0) appendStringInfo(buf, "%*s", padding, process_name()); else appendStringInfoString(buf, process_name()); } break; case 'u': { const char *username = frontend ? frontend->username : "[No Connection]"; if (username == NULL || *username == '\0') username = "[unknown]"; if (padding != 0) appendStringInfo(buf, "%*s", padding, username); else appendStringInfoString(buf, username); } break; case 'd': { const char *dbname = frontend ? frontend->database : "[No Connection]"; if (dbname == NULL || *dbname == '\0') dbname = "[unknown]"; if (padding != 0) appendStringInfo(buf, "%*s", padding, dbname); else appendStringInfoString(buf, dbname); } break; case 'p': if (padding != 0) appendStringInfo(buf, "%*d", padding, myProcPid); else appendStringInfo(buf, "%d", myProcPid); break; case 'l': if (padding != 0) appendStringInfo(buf, "%*ld", padding, log_line_number); else appendStringInfo(buf, "%ld", log_line_number); break; case 't': { time_t now = time(NULL); strftime(strbuf, sizeof(strbuf), "%Y-%m-%d %H:%M:%S", localtime(&now)); if (padding != 0) appendStringInfo(buf, "%*s", padding, strbuf); else appendStringInfoString(buf, strbuf); } break; case 'm': { struct timeval timeval; time_t seconds; struct tm *now; char msbuf[13]; gettimeofday(&timeval, NULL); seconds = timeval.tv_sec; now = localtime(&seconds); strftime(strbuf, sizeof(strbuf), "%Y-%m-%d %H:%M:%S", now); snprintf(msbuf, sizeof(msbuf), ".%03d", (int) (timeval.tv_usec / 1000)); memcpy(strbuf + 19, msbuf, 5); if (padding != 0) appendStringInfo(buf, "%*s", padding, strbuf); else appendStringInfoString(buf, strbuf); } break; default: /* format error - ignore it */ break; } } } /* * Write error report to server's log */ static void send_message_to_server_log(ErrorData *edata) { StringInfoData buf; initStringInfo(&buf); log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfo(&buf, "%s: ", error_severity(edata->elevel, false)); 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 (pool_config->log_error_verbosity >= PGERROR_DEFAULT) { if (edata->detail_log) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfoString(&buf, _("DETAIL: ")); append_with_tabs(&buf, edata->detail_log); appendStringInfoChar(&buf, '\n'); } else if (edata->detail) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfoString(&buf, _("DETAIL: ")); append_with_tabs(&buf, edata->detail); appendStringInfoChar(&buf, '\n'); } if (edata->hint) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfoString(&buf, _("HINT: ")); append_with_tabs(&buf, edata->hint); appendStringInfoChar(&buf, '\n'); } if (edata->internalquery) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfoString(&buf, _("QUERY: ")); append_with_tabs(&buf, edata->internalquery); appendStringInfoChar(&buf, '\n'); } if (edata->context) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfoString(&buf, _("CONTEXT: ")); append_with_tabs(&buf, edata->context); appendStringInfoChar(&buf, '\n'); } if (pool_config->log_error_verbosity >= PGERROR_VERBOSE) { /* assume no newlines in funcname or filename... */ if (edata->funcname && edata->filename) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfo(&buf, _("LOCATION: %s, %s:%d\n"), edata->funcname, edata->filename, edata->lineno); } else if (edata->filename) { log_line_prefix(&buf, pool_config->log_line_prefix, edata); appendStringInfo(&buf, _("LOCATION: %s:%d\n"), edata->filename, edata->lineno); } } } #ifdef HAVE_SYSLOG /* Write to syslog, if enabled */ if (pool_config->log_destination & LOG_DESTINATION_SYSLOG) { int syslog_level; switch (edata->elevel) { case DEBUG5: case DEBUG4: case DEBUG3: case DEBUG2: case DEBUG1: case FRONTEND_DEBUG: syslog_level = LOG_DEBUG; break; case LOG: case COMMERROR: case INFO: case FRONTEND_LOG: syslog_level = LOG_INFO; break; case NOTICE: case WARNING: syslog_level = LOG_NOTICE; break; case ERROR: case FRONTEND_ONLY_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 */ if (pool_config->log_destination & LOG_DESTINATION_STDERR) { /* * Use the chunking protocol if we know the syslogger should be * catching stderr output, and we are not ourselves the syslogger. * Otherwise, just do a vanilla write to stderr. */ if (redirection_done && processType != PT_LOGGER) write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_STDERR); else write_console(buf.data, buf.len); } pfree(buf.data); } /* * 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') { snprintf(errorstr_buf, sizeof(errorstr_buf), /*------ translator: This string will be truncated at 47 characters expanded. */ _("operating system error %d"), errnum); str = errorstr_buf; } return str; } /* * error_severity --- get localized string representing elevel */ static const char * error_severity(int elevel, bool for_frontend) { const char *prefix; switch (elevel) { case DEBUG1: case DEBUG2: case DEBUG3: case DEBUG4: case DEBUG5: case FRONTEND_DEBUG: prefix = _("DEBUG"); break; case LOG: case COMMERROR: case FRONTEND_LOG: prefix = _("LOG"); break; case INFO: prefix = _("INFO"); break; case NOTICE: prefix = _("NOTICE"); break; case WARNING: prefix = _("WARNING"); break; case FRONTEND_ONLY_ERROR: if (for_frontend == false) prefix = _("FRONTEND_ERROR"); else prefix = _("ERROR"); 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'); } } /* * process_name --- get process name string of current process */ static const char * process_name(void) { const char *prefix; switch (processType) { case PT_CHILD: prefix = _("CHILD"); break; case PT_MAIN: prefix = _("MAIN"); break; case PT_WORKER: prefix = _("WORKER"); break; case PT_PCP: prefix = _("PCP CHILD"); break; case PT_PCP_WORKER: prefix = _("PCP WORKER"); break; case PT_HB_SENDER: prefix = _("WD HB SENDER"); break; case PT_HB_RECEIVER: prefix = _("WD HB RECEIVER"); break; case PT_WATCHDOG: prefix = _("WATCHDOG"); break; case PT_LIFECHECK: prefix = _("LIFECHECK"); break; case PT_WATCHDOG_UTILITY: prefix = _("WD UTILITY"); break; case PT_FOLLOWCHILD: prefix = _("UTILITY"); break; default: prefix = ""; break; } return prefix; } /* * 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; #ifdef WIN32 char errbuf[2048]; /* Arbitrary size? */ #endif fmt = _(fmt); va_start(ap, fmt); #ifndef WIN32 /* On Unix, we just fprintf to stderr */ vfprintf(stderr, fmt, ap); fflush(stderr); #else vsnprintf(errbuf, sizeof(errbuf), fmt, ap); /* * 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 */ { write_eventlog(ERROR, errbuf, strlen(errbuf)); } else { /* Not running as service, write to stderr */ write_console(errbuf, strlen(errbuf)); fflush(stderr); } #endif va_end(ap); } /* error cleanup routines */ /* ---------------------------------------------------------------- * proc_exit * * this function calls all the callbacks registered * for it (to free resources) and then calls exit. * * This should be the only function to call exit(). * -cim 2/6/90 * * Unfortunately, we can't really guarantee that add-on code * obeys the rule of not calling exit() directly. So, while * this is the preferred way out of the system, we also register * an atexit callback that will make sure cleanup happens. * ---------------------------------------------------------------- */ void proc_exit(int code) { /* Clean up everything that must be cleaned up */ proc_exit_prepare(code); elog(DEBUG3, "exit(%d)", code); exit(code); } /* * Code shared between proc_exit and the atexit handler. Note that in * normal exit through proc_exit, this will actually be called twice ... * but the second call will have nothing to do. */ static void proc_exit_prepare(int code) { /* * Once we set this flag, we are committed to exit. Any ereport() will * NOT send control back to the main loop, but right back here. */ proc_exit_inprogress = true; /* * Forget any pending cancel or die requests; we're doing our best to * close up shop already. Note that the signal handlers will not set * these flags again, now that proc_exit_inprogress is set. */ /* * Also clear the error context stack, to prevent error callbacks from * being invoked by any elog/ereport calls made during proc_exit. Whatever * context they might want to offer is probably not relevant, and in any * case they are likely to fail outright after we've done things like * aborting any open transaction. (In normal exit scenarios the context * stack should be empty anyway, but it might not be in the case of * elog(FATAL) for example.) */ error_context_stack = NULL; /* * call on exit prepare if some function is specified this extension is * added by pgpool */ if (on_exit_prepare.function) { (*on_exit_prepare.function) (code, on_exit_prepare.arg); on_exit_prepare.function = NULL; } /* do our shared memory exits first */ shmem_exit(code); elog(DEBUG3, "proc_exit(%d): %d callbacks to make", code, on_proc_exit_index); /* * call all the registered callbacks. * * Note that since we decrement on_proc_exit_index each time, if a * callback calls ereport(ERROR) or ereport(FATAL) then it won't be * invoked again when control comes back here (nor will the * previously-completed callbacks). So, an infinite loop should not be * possible. */ while (--on_proc_exit_index >= 0) (*on_proc_exit_list[on_proc_exit_index].function) (code, on_proc_exit_list[on_proc_exit_index].arg); on_proc_exit_index = 0; } /* ------------------ * Run all of the on_shmem_exit routines --- but don't actually exit. * This is used by the postmaster to re-initialize shared memory and * semaphores after a backend dies horribly. * ------------------ */ void shmem_exit(int code) { elog(DEBUG3, "shmem_exit(%d): %d callbacks to make", code, on_shmem_exit_index); /* * call all the registered callbacks. * * As with proc_exit(), we remove each callback from the list before * calling it, to avoid infinite loop in case of error. */ while (--on_shmem_exit_index >= 0) (*on_shmem_exit_list[on_shmem_exit_index].function) (code, on_shmem_exit_list[on_shmem_exit_index].arg); on_shmem_exit_index = 0; } /* ---------------------------------------------------------------- * atexit_callback * * Backstop to ensure that direct calls of exit() don't mess us up. * * Somebody who was being really uncooperative could call _exit(), * but for that case we have a "dead man switch" that will make the * postmaster treat it as a crash --- see pmsignal.c. * ---------------------------------------------------------------- */ static void atexit_callback(void) { /* Clean up everything that must be cleaned up */ /* ... too bad we don't know the real exit code ... */ proc_exit_prepare(-1); } /* ---------------------------------------------------------------- * on_proc_exit * * this function adds a callback function to the list of * functions invoked by proc_exit(). -cim 2/6/90 * ---------------------------------------------------------------- */ void on_proc_exit(pg_on_exit_callback function, Datum arg) { if (on_proc_exit_index >= MAX_ON_EXITS) ereport(FATAL, (errcode(ERRCODE_PROGRAM_LIMIT_EXCEEDED), errmsg_internal("out of on_proc_exit slots"))); on_proc_exit_list[on_proc_exit_index].function = function; on_proc_exit_list[on_proc_exit_index].arg = arg; ++on_proc_exit_index; if (!atexit_callback_setup) { atexit(atexit_callback); atexit_callback_setup = true; } } /* ---------------------------------------------------------------- * on_shmem_exit * * this function adds a callback function to the list of * functions invoked by shmem_exit(). -cim 2/6/90 * ---------------------------------------------------------------- */ void on_shmem_exit(pg_on_exit_callback function, Datum arg) { if (on_shmem_exit_index >= MAX_ON_EXITS) ereport(FATAL, (errcode(ERRCODE_PROGRAM_LIMIT_EXCEEDED), errmsg_internal("out of on_shmem_exit slots"))); on_shmem_exit_list[on_shmem_exit_index].function = function; on_shmem_exit_list[on_shmem_exit_index].arg = arg; ++on_shmem_exit_index; if (!atexit_callback_setup) { atexit(atexit_callback); atexit_callback_setup = true; } } /* ---------------------------------------------------------------- * on_system_exit * * this function adds a callback function which is invoked * just before calling shmem_exit callbacks at process exit * ---------------------------------------------------------------- */ void on_system_exit(pg_on_exit_callback function, Datum arg) { on_exit_prepare.function = function; on_exit_prepare.arg = arg; } /* ---------------------------------------------------------------- * cancel_shmem_exit * * this function removes an entry, if present, from the list of * functions to be invoked by shmem_exit(). For simplicity, * only the latest entry can be removed. (We could work harder * but there is no need for current uses.) * ---------------------------------------------------------------- */ void cancel_shmem_exit(pg_on_exit_callback function, Datum arg) { if (on_shmem_exit_index > 0 && on_shmem_exit_list[on_shmem_exit_index - 1].function == function && on_shmem_exit_list[on_shmem_exit_index - 1].arg == arg) --on_shmem_exit_index; } /* ---------------------------------------------------------------- * on_exit_reset * * this function clears all on_proc_exit() and on_shmem_exit() * registered functions. This is used just after forking a backend, * so that the backend doesn't believe it should call the postmaster's * on-exit routines when it exits... * ---------------------------------------------------------------- */ void on_exit_reset(void) { on_shmem_exit_index = 0; on_proc_exit_index = 0; on_exit_prepare.function = NULL; on_exit_prepare.arg = (Datum) NULL; }