1 /*-------------------------------------------------------------------------
6 * Portions Copyright (c) 1996-2001, PostgreSQL Global Development Group
7 * Portions Copyright (c) 1994, Regents of the University of California
11 * $Header: /cvsroot/pgsql/src/backend/utils/error/elog.c,v 1.82 2001/03/10 04:21:51 tgl Exp $
13 *-------------------------------------------------------------------------
22 #include <sys/types.h>
32 #include "commands/copy.h"
33 #include "libpq/libpq.h"
34 #include "libpq/pqformat.h"
35 #include "miscadmin.h"
36 #include "storage/proc.h"
37 #include "tcop/tcopprot.h"
38 #include "utils/memutils.h"
41 #include "mb/pg_wchar.h"
46 extern CommandDest whereToSendOutput;
50 * 0 = only stdout/stderr
51 * 1 = stdout+stderr and syslog
53 * ... in theory anyway
56 char *Syslog_facility;
59 static void write_syslog(int level, const char *line);
68 #define TIMESTAMP_SIZE 20 /* format `YYYY-MM-DD HH:MM:SS ' */
69 #define PID_SIZE 9 /* format `[123456] ' */
71 static const char * print_timestamp(void);
72 static const char * print_pid(void);
74 static int Debugfile = -1;
75 static int ElogDebugIndentLevel = 0;
77 /*--------------------
79 * Primary error logging function.
81 * 'lev': error level; indicates recovery action to take, if any.
82 * 'fmt': a printf-style string.
83 * Additional arguments, if any, are formatted per %-escapes in 'fmt'.
85 * In addition to the usual %-escapes recognized by printf, "%m" in
86 * fmt is replaced by the error message for the current value of errno.
88 * Note: no newline is needed at the end of the fmt string, since
89 * elog will provide one for the output methods that need it.
91 * If 'lev' is ERROR or worse, control does not return to the caller.
92 * See elog.h for the error level definitions.
96 elog(int lev, const char *fmt, ...)
100 * The expanded format and final output message are dynamically
101 * allocated if necessary, but not if they fit in the "reasonable
102 * size" buffers shown here. In extremis, we'd rather depend on
103 * having a few hundred bytes of stack space than on malloc() still
104 * working (since memory-clobber errors often take out malloc first).
105 * Don't make these buffers unreasonably large though, on pain of
106 * having to chase a bug with no error message.
108 * Note that we use malloc() not palloc() because we want to retain
109 * control if we run out of memory. palloc() would recursively call
110 * elog(ERROR), which would be all right except if we are working on a
111 * FATAL or REALLYFATAL error. We'd lose track of the fatal condition
112 * and report a mere ERROR to outer loop, which would be a Bad Thing.
113 * So, we substitute an appropriate message in-place, without downgrading
114 * the level if it's above ERROR.
116 char fmt_fixedbuf[128];
117 char msg_fixedbuf[256];
118 char *fmt_buf = fmt_fixedbuf;
119 char *msg_buf = msg_fixedbuf;
120 /* this buffer is only used for strange values of lev: */
122 /* this buffer is only used if errno has a bogus value: */
123 char errorstr_buf[32];
124 const char *errorstr;
131 /* size of the prefix needed for timestamp and pid, if enabled */
132 size_t timestamp_size;
134 if (lev <= DEBUG && Debugfile < 0)
135 return; /* ignore debug msgs if noplace to send */
137 /* Save error str before calling any function that might change errno */
138 errorstr = strerror(errno);
140 * Some strerror()s return an empty string for out-of-range errno.
141 * This is ANSI C spec compliant, but not exactly useful.
143 if (errorstr == NULL || *errorstr == '\0')
145 sprintf(errorstr_buf, "error %d", errno);
146 errorstr = errorstr_buf;
149 if (lev == ERROR || lev == FATAL)
152 * Convert initialization errors into fatal errors.
153 * This is probably redundant, because Warn_restart_ready won't
156 if (IsInitProcessingMode())
159 * If we are inside a critical section, all errors become STOP errors.
162 if (CritSectionCount > 0)
166 /* choose message prefix and indent level */
170 indent = ElogDebugIndentLevel - 1;
174 indent = indent % 30;
178 indent = ElogDebugIndentLevel;
182 indent = indent % 30;
192 sprintf(prefix_buf, "FATAL %d: ", lev);
199 timestamp_size += TIMESTAMP_SIZE;
201 timestamp_size += PID_SIZE;
204 * Set up the expanded format, consisting of the prefix string plus
205 * input format, with any %m replaced by strerror() string (since
206 * vsnprintf won't know what to do with %m). To keep space
207 * calculation simple, we only allow one %m.
209 space_needed = timestamp_size + strlen(prefix) + indent + (lineno ? 24 : 0)
210 + strlen(fmt) + strlen(errorstr) + 1;
211 if (space_needed > (int) sizeof(fmt_fixedbuf))
213 fmt_buf = (char *) malloc(space_needed);
216 /* We're up against it, convert to out-of-memory error */
217 fmt_buf = fmt_fixedbuf;
223 fmt = "elog: out of memory"; /* this must fit in
231 strcat(fmt_buf, print_timestamp());
233 strcat(fmt_buf, print_pid());
235 strcat(fmt_buf, prefix);
237 bp = fmt_buf + strlen(fmt_buf);
241 /* If error was in CopyFrom() print the offending line number -- dz */
244 sprintf(bp, "copy: line %d, ", lineno);
246 if (lev == ERROR || lev >= FATAL)
250 for (cp = fmt; *cp; cp++)
252 if (cp[0] == '%' && cp[1] != '\0')
258 * XXX If there are any %'s in errorstr then vsnprintf
259 * will do the Wrong Thing; do we need to cope? Seems
260 * unlikely that % would appear in system errors.
262 strcpy(bp, errorstr);
265 * copy the rest of fmt literally, since we can't afford
266 * to insert another %m.
274 /* copy % and next char --- this avoids trouble with %%m */
285 * Now generate the actual output text using vsnprintf(). Be sure to
286 * leave space for \n added later as well as trailing null.
288 space_needed = sizeof(msg_fixedbuf);
294 nprinted = vsnprintf(msg_buf, space_needed - 2, fmt_buf, ap);
298 * Note: some versions of vsnprintf return the number of chars
299 * actually stored, but at least one returns -1 on failure. Be
300 * conservative about believing whether the print worked.
302 if (nprinted >= 0 && nprinted < space_needed - 3)
304 /* It didn't work, try to get a bigger buffer */
305 if (msg_buf != msg_fixedbuf)
308 msg_buf = (char *) malloc(space_needed);
311 /* We're up against it, convert to out-of-memory error */
312 msg_buf = msg_fixedbuf;
320 strcat(msg_buf, print_timestamp());
322 strcat(msg_buf, print_pid());
323 strcat(msg_buf, prefix);
324 strcat(msg_buf, "elog: out of memory");
330 * Message prepared; send it where it should go
334 /* Write to syslog, if enabled */
342 syslog_level = LOG_DEBUG;
345 syslog_level = LOG_DEBUG;
348 syslog_level = LOG_NOTICE;
351 syslog_level = LOG_WARNING;
354 syslog_level = LOG_ERR;
358 syslog_level = LOG_CRIT;
361 write_syslog(syslog_level, msg_buf + timestamp_size);
363 #endif /* ENABLE_SYSLOG */
365 /* syslog doesn't want a trailing newline, but other destinations do */
366 strcat(msg_buf, "\n");
368 len = strlen(msg_buf);
370 /* Write to debug file, if open and enabled */
371 /* NOTE: debug file is typically pointed at stderr */
372 if (Debugfile >= 0 && Use_syslog <= 1)
373 write(Debugfile, msg_buf, len);
375 if (lev > DEBUG && whereToSendOutput == Remote)
377 /* Send IPC message to the front-end program */
378 MemoryContext oldcxt;
382 * Since backend libpq may call palloc(), switch to a context where
383 * there's fairly likely to be some free space. After all the
384 * pushups above, we don't want to drop the ball by running out of
387 oldcxt = MemoryContextSwitchTo(ErrorContext);
395 * Abort any COPY OUT in progress when an error is detected.
396 * This hack is necessary because of poor design of copy
402 /* exclude the timestamp from msg sent to frontend */
403 pq_puttextmessage(msgtype, msg_buf + timestamp_size);
406 * This flush is normally not necessary, since postgres.c will
407 * flush out waiting data when control returns to the main loop.
408 * But it seems best to leave it here, so that the client has some
409 * clue what happened if the backend dies before getting back to
410 * the main loop ... error/notice messages should not be a
411 * performance-critical path anyway, so an extra flush won't hurt
416 MemoryContextSwitchTo(oldcxt);
419 if (lev > DEBUG && whereToSendOutput != Remote)
423 * We are running as an interactive backend, so just send the
424 * message to stderr. But don't send a duplicate if Debugfile
425 * write, above, already sent to stderr.
427 if (Debugfile != fileno(stderr))
428 fputs(msg_buf, stderr);
431 /* done with the message, release space */
432 if (fmt_buf != fmt_fixedbuf)
434 if (msg_buf != msg_fixedbuf)
438 * Perform error recovery action as specified by lev.
440 if (lev == ERROR || lev == FATAL)
442 /* Prevent immediate interrupt while entering error recovery */
443 ImmediateInterruptOK = false;
446 * For a FATAL error, we let proc_exit clean up and exit.
448 * If we have not yet entered the main backend loop (ie, we are in
449 * the postmaster or in backend startup), we also go directly to
450 * proc_exit. The same is true if anyone tries to report an error
451 * after proc_exit has begun to run. (It's proc_exit's
452 * responsibility to see that this doesn't turn into infinite
453 * recursion!) But in the latter case, we exit with nonzero exit
454 * code to indicate that something's pretty wrong. We also want
455 * to exit with nonzero exit code if not running under the postmaster
456 * (for example, if we are being run from the initdb script, we'd
457 * better return an error status).
459 if (lev == FATAL || !Warn_restart_ready || proc_exit_inprogress)
462 * fflush here is just to improve the odds that we get to see
463 * the error message, in case things are so hosed that proc_exit
464 * crashes. Any other code you might be tempted to add here
465 * should probably be in an on_proc_exit callback instead.
469 proc_exit((int) (proc_exit_inprogress || !IsUnderPostmaster));
473 * Guard against infinite loop from elog() during error recovery.
476 elog(REALLYFATAL, "elog: error during error recovery, giving up!");
480 * Otherwise we can return to the main loop in postgres.c.
482 siglongjmp(Warn_restart, 1);
488 * Serious crash time. Postmaster will observe nonzero process
489 * exit status and kill the other backends too.
491 * XXX: what if we are *in* the postmaster? proc_exit() won't kill
494 ImmediateInterruptOK = false;
500 /* We reach here if lev <= NOTICE. OK to return to caller. */
510 ElogDebugIndentLevel = 0;
512 if (OutputFileName[0])
515 * A debug-output file name was given.
517 * Make sure we can write the file, and find out if it's a tty.
519 if ((fd = open(OutputFileName, O_CREAT | O_APPEND | O_WRONLY,
521 elog(FATAL, "DebugFileOpen: open of %s: %m",
527 * Redirect our stderr to the debug output file.
529 if (!freopen(OutputFileName, "a", stderr))
530 elog(FATAL, "DebugFileOpen: %s reopen as stderr: %m",
532 Debugfile = fileno(stderr);
534 * If the file is a tty and we're running under the postmaster,
535 * try to send stdout there as well (if it isn't a tty then stderr
536 * will block out stdout, so we may as well let stdout go wherever
537 * it was going before).
539 if (istty && IsUnderPostmaster)
540 if (!freopen(OutputFileName, "a", stdout))
541 elog(FATAL, "DebugFileOpen: %s reopen as stdout: %m",
547 * If no filename was specified, send debugging output to stderr. If
548 * stderr has been hosed, try to open a file.
551 if (fcntl(fd, F_GETFD, 0) < 0)
553 snprintf(OutputFileName, MAXPGPATH, "%s%cpg.errors.%d",
554 DataDir, SEP_CHAR, (int) MyProcPid);
555 fd = open(OutputFileName, O_CREAT | O_APPEND | O_WRONLY, 0666);
558 elog(FATAL, "DebugFileOpen: could not open debugging file");
566 * Return a timestamp string like
568 * "2000-06-04 13:12:03 "
571 print_timestamp(void)
574 static char buf[TIMESTAMP_SIZE + 1];
576 curtime = time(NULL);
578 strftime(buf, sizeof(buf),
579 "%Y-%m-%d %H:%M:%S ",
580 localtime(&curtime));
588 * Return a string like
592 * with the current pid.
597 static char buf[PID_SIZE + 1];
599 snprintf(buf, PID_SIZE + 1, "[%d] ", (int)MyProcPid);
607 #ifndef PG_SYSLOG_LIMIT
608 # define PG_SYSLOG_LIMIT 128
612 * Write a message line to syslog if the syslog option is set.
614 * Our problem here is that many syslog implementations don't handle
615 * long messages in an acceptable manner. While this function doesn't
616 * help that fact, it does work around by splitting up messages into
620 write_syslog(int level, const char *line)
622 static bool openlog_done = false;
623 static unsigned long seq = 0;
624 static int syslog_fac = LOG_LOCAL0;
626 int len = strlen(line);
633 if (strcasecmp(Syslog_facility,"LOCAL0") == 0)
634 syslog_fac = LOG_LOCAL0;
635 if (strcasecmp(Syslog_facility,"LOCAL1") == 0)
636 syslog_fac = LOG_LOCAL1;
637 if (strcasecmp(Syslog_facility,"LOCAL2") == 0)
638 syslog_fac = LOG_LOCAL2;
639 if (strcasecmp(Syslog_facility,"LOCAL3") == 0)
640 syslog_fac = LOG_LOCAL3;
641 if (strcasecmp(Syslog_facility,"LOCAL4") == 0)
642 syslog_fac = LOG_LOCAL4;
643 if (strcasecmp(Syslog_facility,"LOCAL5") == 0)
644 syslog_fac = LOG_LOCAL5;
645 if (strcasecmp(Syslog_facility,"LOCAL6") == 0)
646 syslog_fac = LOG_LOCAL6;
647 if (strcasecmp(Syslog_facility,"LOCAL7") == 0)
648 syslog_fac = LOG_LOCAL7;
649 openlog(Syslog_ident, LOG_PID | LOG_NDELAY, syslog_fac);
654 * We add a sequence number to each log message to suppress "same"
659 /* divide into multiple syslog() calls if message is too long */
660 /* or if the message contains embedded NewLine(s) '\n' */
661 if (len > PG_SYSLOG_LIMIT || strchr(line,'\n') != NULL )
667 char buf[PG_SYSLOG_LIMIT+1];
672 /* if we start at a newline, move ahead one char */
680 strncpy(buf, line, PG_SYSLOG_LIMIT);
681 buf[PG_SYSLOG_LIMIT] = '\0';
682 if (strchr(buf,'\n') != NULL)
683 *strchr(buf,'\n') = '\0';
687 /* trim to multibyte letter boundary */
688 buflen = pg_mbcliplen(buf, l, l);
694 /* already word boundary? */
695 if (isspace((unsigned char) line[l]) || line[l] == '\0')
699 /* try to divide at word boundary */
701 while (i > 0 && !isspace((unsigned char) buf[i]))
704 if (i <= 0) /* couldn't divide word boundary */
715 syslog(level, "[%lu-%d] %s", seq, chunk_nr, buf);
722 /* message short enough */
723 syslog(level, "[%lu] %s", seq, line);
727 #endif /* ENABLE_SYSLOG */