diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 07caedde8be9a7a69da264bcd08fa004b11332f8..3b1da18783dad53e12e926077ba588938eaa993a 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -4,7 +4,7 @@ * * Copyright (c) 1994-5, Regents of the University of California * - * $Id: explain.c,v 1.46 1999/08/31 01:28:28 tgl Exp $ + * $Id: explain.c,v 1.47 1999/09/11 19:06:36 tgl Exp $ * */ @@ -28,7 +28,6 @@ typedef struct ExplainState } ExplainState; static char *Explain_PlanToString(Plan *plan, ExplainState *es); -static void printLongNotice(const char *header, const char *message); static void ExplainOneQuery(Query *query, bool verbose, CommandDest dest); /* Convert a null string pointer into "<>" */ @@ -110,7 +109,7 @@ ExplainOneQuery(Query *query, bool verbose, CommandDest dest) s = nodeToString(plan); if (s) { - printLongNotice("QUERY DUMP:\n\n", s); + elog(NOTICE, "QUERY DUMP:\n\n%s", s); pfree(s); } } @@ -120,7 +119,7 @@ ExplainOneQuery(Query *query, bool verbose, CommandDest dest) s = Explain_PlanToString(plan, es); if (s) { - printLongNotice("QUERY PLAN:\n\n", s); + elog(NOTICE, "QUERY PLAN:\n\n%s", s); pfree(s); } } @@ -332,7 +331,6 @@ explain_outNode(StringInfo str, Plan *plan, int indent, ExplainState *es) } es->rtable = saved_rtable; } - return; } static char * @@ -346,22 +344,3 @@ Explain_PlanToString(Plan *plan, ExplainState *es) explain_outNode(&str, plan, 0, es); return str.data; } - -/* - * Print a message that might exceed the size of the elog message buffer. - * This is a crock ... there shouldn't be an upper limit to what you can elog(). - */ -static void -printLongNotice(const char *header, const char *message) -{ - int len = strlen(message); - - elog(NOTICE, "%.20s%.*s", header, ELOG_MAXLEN - 64, message); - len -= ELOG_MAXLEN - 64; - while (len > 0) - { - message += ELOG_MAXLEN - 64; - elog(NOTICE, "%.*s", ELOG_MAXLEN - 64, message); - len -= ELOG_MAXLEN - 64; - } -} diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 056795457001fd32b63e4931c2ebd5125749d25e..11cf762e7d64a51e80a9686820df76e230297bd9 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -7,10 +7,13 @@ * * * IDENTIFICATION - * $Header: /cvsroot/pgsql/src/backend/utils/error/elog.c,v 1.47 1999/07/17 20:18:03 momjian Exp $ + * $Header: /cvsroot/pgsql/src/backend/utils/error/elog.c,v 1.48 1999/09/11 19:06:31 tgl Exp $ * *------------------------------------------------------------------------- */ + +#include "postgres.h" + #include #include #ifndef O_RDONLY @@ -20,8 +23,6 @@ #include #include #include - -#include "postgres.h" #ifdef USE_SYSLOG #include #endif @@ -33,6 +34,10 @@ #include "tcop/tcopprot.h" #include "utils/trace.h" +extern int errno; +extern int sys_nerr; + + #ifdef USE_SYSLOG /* * Global option to control the use of syslog(3) for logging: @@ -51,84 +56,198 @@ static int Debugfile = -1; static int Err_file = -1; static int ElogDebugIndentLevel = 0; -/* +/*-------------------- * elog - * Old error logging function. + * Primary error logging function. + * + * 'lev': error level; indicates recovery action to take, if any. + * 'fmt': a printf-style string. + * Additional arguments, if any, are formatted per %-escapes in 'fmt'. + * + * In addition to the usual %-escapes recognized by printf, "%m" in + * fmt is replaced by the error message for the current value of errno. + * + * Note: no newline is needed at the end of the fmt string, since + * elog will provide one for the output methods that need it. + * + * If 'lev' is ERROR or worse, control does not return to the caller. + * See elog.h for the error level definitions. + *-------------------- */ void -elog(int lev, const char *fmt,...) +elog(int lev, const char *fmt, ...) { va_list ap; - char buf[ELOG_MAXLEN], - line[ELOG_MAXLEN]; - char *bp; + /* + * The expanded format and final output message are dynamically + * allocated if necessary, but not if they fit in the "reasonable + * size" buffers shown here. In extremis, we'd rather depend on + * having a few hundred bytes of stack space than on malloc() still + * working (since memory-clobber errors often take out malloc first). + * Don't make these buffers unreasonably large though, on pain of + * having to chase a bug with no error message. + */ + char fmt_fixedbuf[128]; + char msg_fixedbuf[256]; + char *fmt_buf = fmt_fixedbuf; + char *msg_buf = msg_fixedbuf; + /* this buffer is only used if errno has a bogus value: */ + char errorstr_buf[32]; + const char *errorstr; + const char *prefix; const char *cp; - extern int errno, - sys_nerr; - + char *bp; + int indent = 0; + int space_needed; #ifdef USE_SYSLOG int log_level; - #endif - int len; - int i = 0; - va_start(ap, fmt); - if (lev == DEBUG && Debugfile < 0) - return; + if (lev <= DEBUG && Debugfile < 0) + return; /* ignore debug msgs if noplace to send */ + + /* choose message prefix and indent level */ switch (lev) { case NOIND: - i = ElogDebugIndentLevel - 1; - if (i < 0) - i = 0; - if (i > 30) - i = i % 30; - cp = "DEBUG: "; + indent = ElogDebugIndentLevel - 1; + if (indent < 0) + indent = 0; + if (indent > 30) + indent = indent % 30; + prefix = "DEBUG: "; break; case DEBUG: - i = ElogDebugIndentLevel; - if (i < 0) - i = 0; - if (i > 30) - i = i % 30; - cp = "DEBUG: "; + indent = ElogDebugIndentLevel; + if (indent < 0) + indent = 0; + if (indent > 30) + indent = indent % 30; + prefix = "DEBUG: "; break; case NOTICE: - cp = "NOTICE: "; + prefix = "NOTICE: "; break; case ERROR: - cp = "ERROR: "; + prefix = "ERROR: "; break; default: - sprintf(line, "FATAL %d: ", lev); - cp = line; + /* temporarily use msg buf for prefix */ + sprintf(msg_fixedbuf, "FATAL %d: ", lev); + prefix = msg_fixedbuf; + break; + } + + /* get errno string for %m */ + if (errno < sys_nerr && errno >= 0) + errorstr = strerror(errno); + else + { + sprintf(errorstr_buf, "error %d", errno); + errorstr = errorstr_buf; + } + + /* + * Set up the expanded format, consisting of the prefix string + * plus input format, with any %m replaced by strerror() string + * (since vsnprintf won't know what to do with %m). To keep + * space calculation simple, we only allow one %m. + */ + space_needed = TIMESTAMP_SIZE + strlen(prefix) + indent + + strlen(fmt) + strlen(errorstr) + 1; + if (space_needed > (int) sizeof(fmt_fixedbuf)) + { + fmt_buf = (char *) malloc(space_needed); + if (fmt_buf == NULL) + { + /* We're up against it, convert to fatal out-of-memory error */ + fmt_buf = fmt_fixedbuf; + lev = REALLYFATAL; + fmt = "elog: out of memory"; /* this must fit in fmt_fixedbuf! */ + } } #ifdef ELOG_TIMESTAMPS - strcpy(buf, tprintf_timestamp()); - strcat(buf, cp); + strcpy(fmt_buf, tprintf_timestamp()); + strcat(fmt_buf, prefix); #else - strcpy(buf, cp); + strcpy(fmt_buf, prefix); #endif - bp = buf + strlen(buf); - while (i-- > 0) + bp = fmt_buf + strlen(fmt_buf); + while (indent-- > 0) *bp++ = ' '; for (cp = fmt; *cp; cp++) - if (*cp == '%' && *(cp + 1) == 'm') + { + if (cp[0] == '%' && cp[1] != '\0') { - if (errno < sys_nerr && errno >= 0) - strcpy(bp, strerror(errno)); + if (cp[1] == 'm') + { + /* XXX If there are any %'s in errorstr then vsnprintf + * will do the Wrong Thing; do we need to cope? + * Seems unlikely that % would appear in system errors. + */ + strcpy(bp, errorstr); + /* copy the rest of fmt literally, since we can't + * afford to insert another %m. + */ + strcat(bp, cp+2); + bp += strlen(bp); + break; + } else - sprintf(bp, "error %d", errno); - bp += strlen(bp); - cp++; + { + /* copy % and next char --- this avoids trouble with %%m */ + *bp++ = *cp++; + *bp++ = *cp; + } } else *bp++ = *cp; + } *bp = '\0'; - vsnprintf(line, ELOG_MAXLEN - 1, buf, ap); - va_end(ap); + + /* + * Now generate the actual output text using vsnprintf(). + * Be sure to leave space for \n added later as well as trailing null. + */ + space_needed = sizeof(msg_fixedbuf); + for (;;) + { + int nprinted; + + va_start(ap, fmt); + nprinted = vsnprintf(msg_buf, space_needed - 2, fmt_buf, ap); + va_end(ap); + /* + * Note: some versions of vsnprintf return the number of chars + * actually stored, but at least one returns -1 on failure. + * Be conservative about believing whether the print worked. + */ + if (nprinted >= 0 && nprinted < space_needed - 3) + break; + /* It didn't work, try to get a bigger buffer */ + if (msg_buf != msg_fixedbuf) + free(msg_buf); + space_needed *= 2; + msg_buf = (char *) malloc(space_needed); + if (msg_buf == NULL) + { + /* We're up against it, convert to fatal out-of-memory error */ + msg_buf = msg_fixedbuf; + lev = REALLYFATAL; +#ifdef ELOG_TIMESTAMPS + strcpy(msg_buf, tprintf_timestamp()); + strcat(msg_buf, "FATAL: elog: out of memory"); +#else + strcpy(msg_buf, "FATAL: elog: out of memory"); +#endif + break; + } + } + + /* + * Message prepared; send it where it should go + */ #ifdef USE_SYSLOG switch (lev) @@ -150,14 +269,16 @@ elog(int lev, const char *fmt,...) log_level = LOG_ERR; break; } - write_syslog(log_level, line + TIMESTAMP_SIZE); + write_syslog(log_level, msg_buf + TIMESTAMP_SIZE); #endif - len = strlen(strcat(line, "\n")); - if ((Debugfile > -1) && (UseSyslog <= 1)) - write(Debugfile, line, len); - if (lev == DEBUG || lev == NOIND) - return; + /* syslog doesn't want a trailing newline, but other destinations do */ + strcat(msg_buf, "\n"); + + len = strlen(msg_buf); + + if (Debugfile >= 0 && UseSyslog <= 1) + write(Debugfile, msg_buf, len); /* * If there's an error log file other than our channel to the @@ -167,33 +288,31 @@ elog(int lev, const char *fmt,...) * then writing here can cause this backend to exit without warning * that is, write() does an exit(). In this case, our only hope of * finding out what's going on is if Err_file was set to some disk - * log. This is a major pain. + * log. This is a major pain. (It's probably also long-dead code... + * does anyone still use ultrix?) */ - - if (Err_file > -1 && Debugfile != Err_file && (UseSyslog <= 1)) + if (lev > DEBUG && Err_file >= 0 && + Debugfile != Err_file && UseSyslog <= 1) { - if (write(Err_file, line, len) < 0) + if (write(Err_file, msg_buf, len) < 0) { - write(open("/dev/console", O_WRONLY, 0666), line, len); - fflush(stdout); - fflush(stderr); - proc_exit(lev); + write(open("/dev/console", O_WRONLY, 0666), msg_buf, len); + lev = REALLYFATAL; } fsync(Err_file); } #ifndef PG_STANDALONE - /* Send IPC message to the front-end program */ - if (IsUnderPostmaster && lev > DEBUG) + + if (lev > DEBUG && IsUnderPostmaster) { - /* notices are not errors, handle 'em differently */ + /* Send IPC message to the front-end program */ char msgtype; if (lev == NOTICE) msgtype = 'N'; else { - /* * Abort any COPY OUT in progress when an error is detected. * This hack is necessary because of poor design of copy @@ -203,7 +322,7 @@ elog(int lev, const char *fmt,...) msgtype = 'E'; } /* exclude the timestamp from msg sent to frontend */ - pq_puttextmessage(msgtype, line + TIMESTAMP_SIZE); + pq_puttextmessage(msgtype, msg_buf + TIMESTAMP_SIZE); /* * This flush is normally not necessary, since postgres.c will @@ -211,35 +330,45 @@ elog(int lev, const char *fmt,...) * 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 + * performance-critical path anyway, so an extra flush won't hurt * much ... */ pq_flush(); } - if (!IsUnderPostmaster) - { - /* - * There is no socket. One explanation for this is we are running - * as the Postmaster. So we'll write the message to stderr. + if (lev > DEBUG && ! IsUnderPostmaster) + { + /* We are running as an interactive backend, so just send + * the message to stderr. */ - fputs(line, stderr); + fputs(msg_buf, stderr); } + #endif /* !PG_STANDALONE */ + /* done with the message, release space */ + if (fmt_buf != fmt_fixedbuf) + free(fmt_buf); + if (msg_buf != msg_fixedbuf) + free(msg_buf); + + /* + * Perform error recovery action as specified by lev. + */ if (lev == ERROR) { - ProcReleaseSpins(NULL); /* get rid of spinlocks we hold */ - if (!InError) + if (InError) { - /* exit to main loop */ - siglongjmp(Warn_restart, 1); + /* error reported during error recovery; don't loop forever */ + elog(REALLYFATAL, "elog: error during error recovery, giving up!"); } + /* exit to main loop */ + ProcReleaseSpins(NULL); /* get rid of spinlocks we hold */ + siglongjmp(Warn_restart, 1); } if (lev == FATAL) { - /* * Assume that if we have detected the failure we can exit with a * normal exit status. This will prevent the postmaster from @@ -254,13 +383,20 @@ elog(int lev, const char *fmt,...) if (lev > FATAL) { + /* + * Serious crash time. Postmaster will observe nonzero + * process exit status and kill the other backends too. + */ fflush(stdout); fflush(stderr); proc_exit(lev); } + + /* We reach here if lev <= NOTICE. OK to return to caller. */ } #ifndef PG_STANDALONE + int DebugFileOpen(void) { diff --git a/src/backend/utils/misc/trace.c b/src/backend/utils/misc/trace.c index baf8ce6121868bc050835f4322c372e701ea7067..3d9cbe607de145d48dec4ce845bc85eb6b66975e 100644 --- a/src/backend/utils/misc/trace.c +++ b/src/backend/utils/misc/trace.c @@ -2,22 +2,21 @@ * * trace.c * - * Conditional trace ans logging functions. + * Conditional trace and logging functions. * * Massimo Dal Zotto * *------------------------------------------------------------------------- */ +#include "postgres.h" + #include #include #include #include #include #include - -#include "postgres.h" - #ifdef USE_SYSLOG #include #endif @@ -25,6 +24,13 @@ #include "miscadmin.h" #include "utils/trace.h" +/* + * We could support trace messages of indefinite length, as elog() does, + * but it's probably not worth the trouble. Instead limit trace message + * length to this. + */ +#define TRACEMSG_MAXLEN 1024 + #ifdef USE_SYSLOG /* * Global option to control the use of syslog(3) for logging: @@ -87,15 +93,14 @@ int tprintf(int flag, const char *fmt,...) { va_list ap; - char line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1]; - + char line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1]; #ifdef USE_SYSLOG int log_level; #endif if ((flag == TRACE_ALL) || (pg_options[TRACE_ALL] > 0)) { - /* uconditional trace or trace all option set */ + /* unconditional trace or trace all option set */ } else if (pg_options[TRACE_ALL] == 0) { @@ -105,11 +110,11 @@ tprintf(int flag, const char *fmt,...) else if (pg_options[TRACE_ALL] < 0) return 0; - va_start(ap, fmt); #ifdef ELOG_TIMESTAMPS strcpy(line, tprintf_timestamp()); #endif - vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap); + va_start(ap, fmt); + vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap); va_end(ap); #ifdef USE_SYSLOG @@ -134,13 +139,13 @@ int tprintf1(const char *fmt,...) { va_list ap; - char line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1]; + char line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1]; - va_start(ap, fmt); #ifdef ELOG_TIMESTAMPS strcpy(line, tprintf_timestamp()); #endif - vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap); + va_start(ap, fmt); + vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap); va_end(ap); #ifdef USE_SYSLOG @@ -164,13 +169,13 @@ int eprintf(const char *fmt,...) { va_list ap; - char line[ELOG_MAXLEN + TIMESTAMP_SIZE + 1]; + char line[TRACEMSG_MAXLEN + TIMESTAMP_SIZE + 1]; - va_start(ap, fmt); #ifdef ELOG_TIMESTAMPS strcpy(line, tprintf_timestamp()); #endif - vsnprintf(line + TIMESTAMP_SIZE, ELOG_MAXLEN, fmt, ap); + va_start(ap, fmt); + vsnprintf(line + TIMESTAMP_SIZE, TRACEMSG_MAXLEN, fmt, ap); va_end(ap); #ifdef USE_SYSLOG diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h index ae9ca209417acee419f0233e94238f7aa5d79d45..5f64a6b1c7723e30c69d89dc62f3fd98b587ba9c 100644 --- a/src/include/utils/elog.h +++ b/src/include/utils/elog.h @@ -6,7 +6,7 @@ * * Copyright (c) 1994, Regents of the University of California * - * $Id: elog.h,v 1.11 1999/07/13 21:17:42 momjian Exp $ + * $Id: elog.h,v 1.12 1999/09/11 19:06:25 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -14,36 +14,16 @@ #define ELOG_H #define NOTICE 0 /* random info - no special action */ -#define ERROR -1 /* user error - return to known state */ -#define FATAL 1 /* Fatal error - abort process */ -#define DEBUG -2 /* debug message */ -#define NOIND -3 /* debug message, don't indent as far */ - -#ifdef NOT_USED -#define PTIME 0x100 /* prepend time to message */ -#define POS 0x200 /* prepend source position to message */ -#define USERMSG 0x400 /* send message to user */ -#define TERM 0x800 /* send message to terminal */ -#define DBLOG 0x1000 /* put message in per db log */ -#define SLOG 0x2000 /* put message in system log */ -#define ABORTX 0x4000 /* abort process after logging */ -#endif - -/* Increase this to be able to use postmaster -d 3 with complex - * view definitions (which are transformed to very, very large INSERT statements - * and if -d 3 is used the query string of these statements is printed using - * vsprintf which expects enough memory reserved! */ -#define ELOG_MAXLEN 12288 +#define ERROR (-1) /* user error - return to known state */ +#define FATAL 1 /* fatal error - abort process */ +#define REALLYFATAL 2 /* take down the other backends with me */ +#define DEBUG (-2) /* debug message */ +#define NOIND (-3) /* debug message, don't indent as far */ - -/* uncomment the following if you want your elog's to be timestamped */ -/* #define ELOG_TIMESTAMPS */ - -extern void elog(int lev, const char *fmt,...); +extern void elog(int lev, const char *fmt, ...); #ifndef PG_STANDALONE -int DebugFileOpen(void); - +extern int DebugFileOpen(void); #endif #endif /* ELOG_H */