OSDN Git Service

3b86de353b59b52300759ec647e71b53f1e55bc1
[pg-rex/syncrep.git] / src / backend / utils / error / elog.c
1 /*-------------------------------------------------------------------------
2  *
3  * elog.c
4  *        error logging and reporting
5  *
6  * Some notes about recursion and errors during error processing:
7  *
8  * We need to be robust about recursive-error scenarios --- for example,
9  * if we run out of memory, it's important to be able to report that fact.
10  * There are a number of considerations that go into this.
11  *
12  * First, distinguish between re-entrant use and actual recursion.      It
13  * is possible for an error or warning message to be emitted while the
14  * parameters for an error message are being computed.  In this case
15  * errstart has been called for the outer message, and some field values
16  * may have already been saved, but we are not actually recursing.      We handle
17  * this by providing a (small) stack of ErrorData records.      The inner message
18  * can be computed and sent without disturbing the state of the outer message.
19  * (If the inner message is actually an error, this isn't very interesting
20  * because control won't come back to the outer message generator ... but
21  * if the inner message is only debug or log data, this is critical.)
22  *
23  * Second, actual recursion will occur if an error is reported by one of
24  * the elog.c routines or something they call.  By far the most probable
25  * scenario of this sort is "out of memory"; and it's also the nastiest
26  * to handle because we'd likely also run out of memory while trying to
27  * report this error!  Our escape hatch for this case is to reset the
28  * ErrorContext to empty before trying to process the inner error.      Since
29  * ErrorContext is guaranteed to have at least 8K of space in it (see mcxt.c),
30  * we should be able to process an "out of memory" message successfully.
31  * Since we lose the prior error state due to the reset, we won't be able
32  * to return to processing the original error, but we wouldn't have anyway.
33  * (NOTE: the escape hatch is not used for recursive situations where the
34  * inner message is of less than ERROR severity; in that case we just
35  * try to process it and return normally.  Usually this will work, but if
36  * it ends up in infinite recursion, we will PANIC due to error stack
37  * overflow.)
38  *
39  *
40  * Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
41  * Portions Copyright (c) 1994, Regents of the University of California
42  *
43  *
44  * IDENTIFICATION
45  *        $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.190 2007/07/21 22:12:04 tgl Exp $
46  *
47  *-------------------------------------------------------------------------
48  */
49 #include "postgres.h"
50
51 #include <fcntl.h>
52 #include <time.h>
53 #include <unistd.h>
54 #include <signal.h>
55 #include <ctype.h>
56 #ifdef HAVE_SYSLOG
57 #include <syslog.h>
58 #endif
59
60 #include "access/transam.h"
61 #include "access/xact.h"
62 #include "libpq/libpq.h"
63 #include "libpq/pqformat.h"
64 #include "mb/pg_wchar.h"
65 #include "miscadmin.h"
66 #include "postmaster/postmaster.h"
67 #include "postmaster/syslogger.h"
68 #include "storage/ipc.h"
69 #include "tcop/tcopprot.h"
70 #include "utils/memutils.h"
71 #include "utils/ps_status.h"
72
73
74 /* Global variables */
75 ErrorContextCallback *error_context_stack = NULL;
76
77 sigjmp_buf *PG_exception_stack = NULL;
78
79 extern bool redirection_done;
80
81 /* GUC parameters */
82 PGErrorVerbosity Log_error_verbosity = PGERROR_VERBOSE;
83 char       *Log_line_prefix = NULL;             /* format for extra log line info */
84 int                     Log_destination = LOG_DESTINATION_STDERR;
85
86 #ifdef HAVE_SYSLOG
87 static bool openlog_done = false;
88 static char *syslog_ident = NULL;
89 static int      syslog_facility = LOG_LOCAL0;
90
91 static void write_syslog(int level, const char *line);
92 #endif
93
94 #ifdef WIN32
95 static void write_eventlog(int level, const char *line);
96 #endif
97
98 /* We provide a small stack of ErrorData records for re-entrant cases */
99 #define ERRORDATA_STACK_SIZE  5
100
101 static ErrorData errordata[ERRORDATA_STACK_SIZE];
102
103 static int      errordata_stack_depth = -1; /* index of topmost active frame */
104
105 static int      recursion_depth = 0;    /* to detect actual recursion */
106
107
108 /* Macro for checking errordata_stack_depth is reasonable */
109 #define CHECK_STACK_DEPTH() \
110         do { \
111                 if (errordata_stack_depth < 0) \
112                 { \
113                         errordata_stack_depth = -1; \
114                         ereport(ERROR, (errmsg_internal("errstart was not called"))); \
115                 } \
116         } while (0)
117
118
119 static void log_line_prefix(StringInfo buf);
120 static void send_message_to_server_log(ErrorData *edata);
121 static void send_message_to_frontend(ErrorData *edata);
122 static char *expand_fmt_string(const char *fmt, ErrorData *edata);
123 static const char *useful_strerror(int errnum);
124 static const char *error_severity(int elevel);
125 static void append_with_tabs(StringInfo buf, const char *str);
126 static bool is_log_level_output(int elevel, int log_min_level);
127 static void write_pipe_chunks(int fd, char *data, int len);
128
129
130 /*
131  * errstart --- begin an error-reporting cycle
132  *
133  * Create a stack entry and store the given parameters in it.  Subsequently,
134  * errmsg() and perhaps other routines will be called to further populate
135  * the stack entry.  Finally, errfinish() will be called to actually process
136  * the error report.
137  *
138  * Returns TRUE in normal case.  Returns FALSE to short-circuit the error
139  * report (if it's a warning or lower and not to be reported anywhere).
140  */
141 bool
142 errstart(int elevel, const char *filename, int lineno,
143                  const char *funcname)
144 {
145         ErrorData  *edata;
146         bool            output_to_server;
147         bool            output_to_client = false;
148         int                     i;
149
150         /*
151          * Check some cases in which we want to promote an error into a more
152          * severe error.  None of this logic applies for non-error messages.
153          */
154         if (elevel >= ERROR)
155         {
156                 /*
157                  * If we are inside a critical section, all errors become PANIC
158                  * errors.      See miscadmin.h.
159                  */
160                 if (CritSectionCount > 0)
161                         elevel = PANIC;
162
163                 /*
164                  * Check reasons for treating ERROR as FATAL:
165                  *
166                  * 1. we have no handler to pass the error to (implies we are in the
167                  * postmaster or in backend startup).
168                  *
169                  * 2. ExitOnAnyError mode switch is set (initdb uses this).
170                  *
171                  * 3. the error occurred after proc_exit has begun to run.      (It's
172                  * proc_exit's responsibility to see that this doesn't turn into
173                  * infinite recursion!)
174                  */
175                 if (elevel == ERROR)
176                 {
177                         if (PG_exception_stack == NULL ||
178                                 ExitOnAnyError ||
179                                 proc_exit_inprogress)
180                                 elevel = FATAL;
181                 }
182
183                 /*
184                  * If the error level is ERROR or more, errfinish is not going to
185                  * return to caller; therefore, if there is any stacked error already
186                  * in progress it will be lost.  This is more or less okay, except we
187                  * do not want to have a FATAL or PANIC error downgraded because the
188                  * reporting process was interrupted by a lower-grade error.  So check
189                  * the stack and make sure we panic if panic is warranted.
190                  */
191                 for (i = 0; i <= errordata_stack_depth; i++)
192                         elevel = Max(elevel, errordata[i].elevel);
193         }
194
195         /*
196          * Now decide whether we need to process this report at all; if it's
197          * warning or less and not enabled for logging, just return FALSE without
198          * starting up any error logging machinery.
199          */
200
201         /* Determine whether message is enabled for server log output */
202         if (IsPostmasterEnvironment)
203                 output_to_server = is_log_level_output(elevel, log_min_messages);
204         else
205                 /* In bootstrap/standalone case, do not sort LOG out-of-order */
206                 output_to_server = (elevel >= log_min_messages);
207
208         /* Determine whether message is enabled for client output */
209         if (whereToSendOutput == DestRemote && elevel != COMMERROR)
210         {
211                 /*
212                  * client_min_messages is honored only after we complete the
213                  * authentication handshake.  This is required both for security
214                  * reasons and because many clients can't handle NOTICE messages
215                  * during authentication.
216                  */
217                 if (ClientAuthInProgress)
218                         output_to_client = (elevel >= ERROR);
219                 else
220                         output_to_client = (elevel >= client_min_messages ||
221                                                                 elevel == INFO);
222         }
223
224         /* Skip processing effort if non-error message will not be output */
225         if (elevel < ERROR && !output_to_server && !output_to_client)
226                 return false;
227
228         /*
229          * Okay, crank up a stack entry to store the info in.
230          */
231
232         if (recursion_depth++ > 0 && elevel >= ERROR)
233         {
234                 /*
235                  * Ooops, error during error processing.  Clear ErrorContext as
236                  * discussed at top of file.  We will not return to the original
237                  * error's reporter or handler, so we don't need it.
238                  */
239                 MemoryContextReset(ErrorContext);
240
241                 /*
242                  * If we recurse more than once, the problem might be something broken
243                  * in a context traceback routine.  Abandon them too.  We also
244                  * abandon attempting to print the error statement (which, if long,
245                  * could itself be the source of the recursive failure).
246                  */
247                 if (recursion_depth > 2)
248                 {
249                         error_context_stack = NULL;
250                         debug_query_string = NULL;
251                 }
252         }
253         if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
254         {
255                 /*
256                  * Wups, stack not big enough.  We treat this as a PANIC condition
257                  * because it suggests an infinite loop of errors during error
258                  * recovery.
259                  */
260                 errordata_stack_depth = -1;             /* make room on stack */
261                 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
262         }
263
264         /* Initialize data for this error frame */
265         edata = &errordata[errordata_stack_depth];
266         MemSet(edata, 0, sizeof(ErrorData));
267         edata->elevel = elevel;
268         edata->output_to_server = output_to_server;
269         edata->output_to_client = output_to_client;
270         edata->filename = filename;
271         edata->lineno = lineno;
272         edata->funcname = funcname;
273         /* Select default errcode based on elevel */
274         if (elevel >= ERROR)
275                 edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
276         else if (elevel == WARNING)
277                 edata->sqlerrcode = ERRCODE_WARNING;
278         else
279                 edata->sqlerrcode = ERRCODE_SUCCESSFUL_COMPLETION;
280         /* errno is saved here so that error parameter eval can't change it */
281         edata->saved_errno = errno;
282
283         recursion_depth--;
284         return true;
285 }
286
287 /*
288  * errfinish --- end an error-reporting cycle
289  *
290  * Produce the appropriate error report(s) and pop the error stack.
291  *
292  * If elevel is ERROR or worse, control does not return to the caller.
293  * See elog.h for the error level definitions.
294  */
295 void
296 errfinish(int dummy,...)
297 {
298         ErrorData  *edata = &errordata[errordata_stack_depth];
299         int                     elevel = edata->elevel;
300         MemoryContext oldcontext;
301         ErrorContextCallback *econtext;
302
303         recursion_depth++;
304         CHECK_STACK_DEPTH();
305
306         /*
307          * Do processing in ErrorContext, which we hope has enough reserved space
308          * to report an error.
309          */
310         oldcontext = MemoryContextSwitchTo(ErrorContext);
311
312         /*
313          * Call any context callback functions.  Errors occurring in callback
314          * functions will be treated as recursive errors --- this ensures we will
315          * avoid infinite recursion (see errstart).
316          */
317         for (econtext = error_context_stack;
318                  econtext != NULL;
319                  econtext = econtext->previous)
320                 (*econtext->callback) (econtext->arg);
321
322         /*
323          * If ERROR (not more nor less) we pass it off to the current handler.
324          * Printing it and popping the stack is the responsibility of the handler.
325          */
326         if (elevel == ERROR)
327         {
328                 /*
329                  * We do some minimal cleanup before longjmp'ing so that handlers can
330                  * execute in a reasonably sane state.
331                  */
332
333                 /* This is just in case the error came while waiting for input */
334                 ImmediateInterruptOK = false;
335
336                 /*
337                  * Reset InterruptHoldoffCount in case we ereport'd from inside an
338                  * interrupt holdoff section.  (We assume here that no handler will
339                  * itself be inside a holdoff section.  If necessary, such a handler
340                  * could save and restore InterruptHoldoffCount for itself, but this
341                  * should make life easier for most.)
342                  */
343                 InterruptHoldoffCount = 0;
344
345                 CritSectionCount = 0;   /* should be unnecessary, but... */
346
347                 /*
348                  * Note that we leave CurrentMemoryContext set to ErrorContext. The
349                  * handler should reset it to something else soon.
350                  */
351
352                 recursion_depth--;
353                 PG_RE_THROW();
354         }
355
356         /*
357          * If we are doing FATAL or PANIC, abort any old-style COPY OUT in
358          * progress, so that we can report the message before dying.  (Without
359          * this, pq_putmessage will refuse to send the message at all, which is
360          * what we want for NOTICE messages, but not for fatal exits.) This hack
361          * is necessary because of poor design of old-style copy protocol.      Note
362          * we must do this even if client is fool enough to have set
363          * client_min_messages above FATAL, so don't look at output_to_client.
364          */
365         if (elevel >= FATAL && whereToSendOutput == DestRemote)
366                 pq_endcopyout(true);
367
368         /* Emit the message to the right places */
369         EmitErrorReport();
370
371         /* Now free up subsidiary data attached to stack entry, and release it */
372         if (edata->message)
373                 pfree(edata->message);
374         if (edata->detail)
375                 pfree(edata->detail);
376         if (edata->hint)
377                 pfree(edata->hint);
378         if (edata->context)
379                 pfree(edata->context);
380         if (edata->internalquery)
381                 pfree(edata->internalquery);
382
383         errordata_stack_depth--;
384
385         /* Exit error-handling context */
386         MemoryContextSwitchTo(oldcontext);
387         recursion_depth--;
388
389         /*
390          * Perform error recovery action as specified by elevel.
391          */
392         if (elevel == FATAL)
393         {
394                 /*
395                  * For a FATAL error, we let proc_exit clean up and exit.
396                  */
397                 ImmediateInterruptOK = false;
398
399                 /*
400                  * If we just reported a startup failure, the client will disconnect
401                  * on receiving it, so don't send any more to the client.
402                  */
403                 if (PG_exception_stack == NULL && whereToSendOutput == DestRemote)
404                         whereToSendOutput = DestNone;
405
406                 /*
407                  * fflush here is just to improve the odds that we get to see the
408                  * error message, in case things are so hosed that proc_exit crashes.
409                  * Any other code you might be tempted to add here should probably be
410                  * in an on_proc_exit or on_shmem_exit callback instead.
411                  */
412                 fflush(stdout);
413                 fflush(stderr);
414
415                 /*
416                  * Do normal process-exit cleanup, then return exit code 1 to indicate
417                  * FATAL termination.  The postmaster may or may not consider this
418                  * worthy of panic, depending on which subprocess returns it.
419                  */
420                 proc_exit(1);
421         }
422
423         if (elevel >= PANIC)
424         {
425                 /*
426                  * Serious crash time. Postmaster will observe SIGABRT process exit
427                  * status and kill the other backends too.
428                  *
429                  * XXX: what if we are *in* the postmaster?  abort() won't kill our
430                  * children...
431                  */
432                 ImmediateInterruptOK = false;
433                 fflush(stdout);
434                 fflush(stderr);
435                 abort();
436         }
437
438         /*
439          * We reach here if elevel <= WARNING. OK to return to caller.
440          *
441          * But check for cancel/die interrupt first --- this is so that the user
442          * can stop a query emitting tons of notice or warning messages, even if
443          * it's in a loop that otherwise fails to check for interrupts.
444          */
445         CHECK_FOR_INTERRUPTS();
446 }
447
448
449 /*
450  * errcode --- add SQLSTATE error code to the current error
451  *
452  * The code is expected to be represented as per MAKE_SQLSTATE().
453  */
454 int
455 errcode(int sqlerrcode)
456 {
457         ErrorData  *edata = &errordata[errordata_stack_depth];
458
459         /* we don't bother incrementing recursion_depth */
460         CHECK_STACK_DEPTH();
461
462         edata->sqlerrcode = sqlerrcode;
463
464         return 0;                                       /* return value does not matter */
465 }
466
467
468 /*
469  * errcode_for_file_access --- add SQLSTATE error code to the current error
470  *
471  * The SQLSTATE code is chosen based on the saved errno value.  We assume
472  * that the failing operation was some type of disk file access.
473  *
474  * NOTE: the primary error message string should generally include %m
475  * when this is used.
476  */
477 int
478 errcode_for_file_access(void)
479 {
480         ErrorData  *edata = &errordata[errordata_stack_depth];
481
482         /* we don't bother incrementing recursion_depth */
483         CHECK_STACK_DEPTH();
484
485         switch (edata->saved_errno)
486         {
487                         /* Permission-denied failures */
488                 case EPERM:                             /* Not super-user */
489                 case EACCES:                    /* Permission denied */
490 #ifdef EROFS
491                 case EROFS:                             /* Read only file system */
492 #endif
493                         edata->sqlerrcode = ERRCODE_INSUFFICIENT_PRIVILEGE;
494                         break;
495
496                         /* File not found */
497                 case ENOENT:                    /* No such file or directory */
498                         edata->sqlerrcode = ERRCODE_UNDEFINED_FILE;
499                         break;
500
501                         /* Duplicate file */
502                 case EEXIST:                    /* File exists */
503                         edata->sqlerrcode = ERRCODE_DUPLICATE_FILE;
504                         break;
505
506                         /* Wrong object type or state */
507                 case ENOTDIR:                   /* Not a directory */
508                 case EISDIR:                    /* Is a directory */
509 #if defined(ENOTEMPTY) && (ENOTEMPTY != EEXIST) /* same code on AIX */
510                 case ENOTEMPTY: /* Directory not empty */
511 #endif
512                         edata->sqlerrcode = ERRCODE_WRONG_OBJECT_TYPE;
513                         break;
514
515                         /* Insufficient resources */
516                 case ENOSPC:                    /* No space left on device */
517                         edata->sqlerrcode = ERRCODE_DISK_FULL;
518                         break;
519
520                 case ENFILE:                    /* File table overflow */
521                 case EMFILE:                    /* Too many open files */
522                         edata->sqlerrcode = ERRCODE_INSUFFICIENT_RESOURCES;
523                         break;
524
525                         /* Hardware failure */
526                 case EIO:                               /* I/O error */
527                         edata->sqlerrcode = ERRCODE_IO_ERROR;
528                         break;
529
530                         /* All else is classified as internal errors */
531                 default:
532                         edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
533                         break;
534         }
535
536         return 0;                                       /* return value does not matter */
537 }
538
539 /*
540  * errcode_for_socket_access --- add SQLSTATE error code to the current error
541  *
542  * The SQLSTATE code is chosen based on the saved errno value.  We assume
543  * that the failing operation was some type of socket access.
544  *
545  * NOTE: the primary error message string should generally include %m
546  * when this is used.
547  */
548 int
549 errcode_for_socket_access(void)
550 {
551         ErrorData  *edata = &errordata[errordata_stack_depth];
552
553         /* we don't bother incrementing recursion_depth */
554         CHECK_STACK_DEPTH();
555
556         switch (edata->saved_errno)
557         {
558                         /* Loss of connection */
559                 case EPIPE:
560 #ifdef ECONNRESET
561                 case ECONNRESET:
562 #endif
563                         edata->sqlerrcode = ERRCODE_CONNECTION_FAILURE;
564                         break;
565
566                         /* All else is classified as internal errors */
567                 default:
568                         edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
569                         break;
570         }
571
572         return 0;                                       /* return value does not matter */
573 }
574
575
576 /*
577  * This macro handles expansion of a format string and associated parameters;
578  * it's common code for errmsg(), errdetail(), etc.  Must be called inside
579  * a routine that is declared like "const char *fmt, ..." and has an edata
580  * pointer set up.      The message is assigned to edata->targetfield, or
581  * appended to it if appendval is true.
582  *
583  * Note: we pstrdup the buffer rather than just transferring its storage
584  * to the edata field because the buffer might be considerably larger than
585  * really necessary.
586  */
587 #define EVALUATE_MESSAGE(targetfield, appendval)  \
588         { \
589                 char               *fmtbuf; \
590                 StringInfoData  buf; \
591                 /* Internationalize the error format string */ \
592                 fmt = _(fmt); \
593                 /* Expand %m in format string */ \
594                 fmtbuf = expand_fmt_string(fmt, edata); \
595                 initStringInfo(&buf); \
596                 if ((appendval) && edata->targetfield) \
597                         appendStringInfo(&buf, "%s\n", edata->targetfield); \
598                 /* Generate actual output --- have to use appendStringInfoVA */ \
599                 for (;;) \
600                 { \
601                         va_list         args; \
602                         bool            success; \
603                         va_start(args, fmt); \
604                         success = appendStringInfoVA(&buf, fmtbuf, args); \
605                         va_end(args); \
606                         if (success) \
607                                 break; \
608                         enlargeStringInfo(&buf, buf.maxlen); \
609                 } \
610                 /* Done with expanded fmt */ \
611                 pfree(fmtbuf); \
612                 /* Save the completed message into the stack item */ \
613                 if (edata->targetfield) \
614                         pfree(edata->targetfield); \
615                 edata->targetfield = pstrdup(buf.data); \
616                 pfree(buf.data); \
617         }
618
619
620 /*
621  * errmsg --- add a primary error message text to the current error
622  *
623  * In addition to the usual %-escapes recognized by printf, "%m" in
624  * fmt is replaced by the error message for the caller's value of errno.
625  *
626  * Note: no newline is needed at the end of the fmt string, since
627  * ereport will provide one for the output methods that need it.
628  */
629 int
630 errmsg(const char *fmt,...)
631 {
632         ErrorData  *edata = &errordata[errordata_stack_depth];
633         MemoryContext oldcontext;
634
635         recursion_depth++;
636         CHECK_STACK_DEPTH();
637         oldcontext = MemoryContextSwitchTo(ErrorContext);
638
639         EVALUATE_MESSAGE(message, false);
640
641         MemoryContextSwitchTo(oldcontext);
642         recursion_depth--;
643         return 0;                                       /* return value does not matter */
644 }
645
646
647 /*
648  * errmsg_internal --- add a primary error message text to the current error
649  *
650  * This is exactly like errmsg() except that strings passed to errmsg_internal
651  * are customarily left out of the internationalization message dictionary.
652  * This should be used for "can't happen" cases that are probably not worth
653  * spending translation effort on.
654  */
655 int
656 errmsg_internal(const char *fmt,...)
657 {
658         ErrorData  *edata = &errordata[errordata_stack_depth];
659         MemoryContext oldcontext;
660
661         recursion_depth++;
662         CHECK_STACK_DEPTH();
663         oldcontext = MemoryContextSwitchTo(ErrorContext);
664
665         EVALUATE_MESSAGE(message, false);
666
667         MemoryContextSwitchTo(oldcontext);
668         recursion_depth--;
669         return 0;                                       /* return value does not matter */
670 }
671
672
673 /*
674  * errdetail --- add a detail error message text to the current error
675  */
676 int
677 errdetail(const char *fmt,...)
678 {
679         ErrorData  *edata = &errordata[errordata_stack_depth];
680         MemoryContext oldcontext;
681
682         recursion_depth++;
683         CHECK_STACK_DEPTH();
684         oldcontext = MemoryContextSwitchTo(ErrorContext);
685
686         EVALUATE_MESSAGE(detail, false);
687
688         MemoryContextSwitchTo(oldcontext);
689         recursion_depth--;
690         return 0;                                       /* return value does not matter */
691 }
692
693
694 /*
695  * errhint --- add a hint error message text to the current error
696  */
697 int
698 errhint(const char *fmt,...)
699 {
700         ErrorData  *edata = &errordata[errordata_stack_depth];
701         MemoryContext oldcontext;
702
703         recursion_depth++;
704         CHECK_STACK_DEPTH();
705         oldcontext = MemoryContextSwitchTo(ErrorContext);
706
707         EVALUATE_MESSAGE(hint, false);
708
709         MemoryContextSwitchTo(oldcontext);
710         recursion_depth--;
711         return 0;                                       /* return value does not matter */
712 }
713
714
715 /*
716  * errcontext --- add a context error message text to the current error
717  *
718  * Unlike other cases, multiple calls are allowed to build up a stack of
719  * context information.  We assume earlier calls represent more-closely-nested
720  * states.
721  */
722 int
723 errcontext(const char *fmt,...)
724 {
725         ErrorData  *edata = &errordata[errordata_stack_depth];
726         MemoryContext oldcontext;
727
728         recursion_depth++;
729         CHECK_STACK_DEPTH();
730         oldcontext = MemoryContextSwitchTo(ErrorContext);
731
732         EVALUATE_MESSAGE(context, true);
733
734         MemoryContextSwitchTo(oldcontext);
735         recursion_depth--;
736         return 0;                                       /* return value does not matter */
737 }
738
739
740 /*
741  * errhidestmt --- optionally suppress STATEMENT: field of log entry
742  *
743  * This should be called if the message text already includes the statement.
744  */
745 int
746 errhidestmt(bool hide_stmt)
747 {
748         ErrorData  *edata = &errordata[errordata_stack_depth];
749
750         /* we don't bother incrementing recursion_depth */
751         CHECK_STACK_DEPTH();
752
753         edata->hide_stmt = hide_stmt;
754
755         return 0;                                       /* return value does not matter */
756 }
757
758
759 /*
760  * errfunction --- add reporting function name to the current error
761  *
762  * This is used when backwards compatibility demands that the function
763  * name appear in messages sent to old-protocol clients.  Note that the
764  * passed string is expected to be a non-freeable constant string.
765  */
766 int
767 errfunction(const char *funcname)
768 {
769         ErrorData  *edata = &errordata[errordata_stack_depth];
770
771         /* we don't bother incrementing recursion_depth */
772         CHECK_STACK_DEPTH();
773
774         edata->funcname = funcname;
775         edata->show_funcname = true;
776
777         return 0;                                       /* return value does not matter */
778 }
779
780 /*
781  * errposition --- add cursor position to the current error
782  */
783 int
784 errposition(int cursorpos)
785 {
786         ErrorData  *edata = &errordata[errordata_stack_depth];
787
788         /* we don't bother incrementing recursion_depth */
789         CHECK_STACK_DEPTH();
790
791         edata->cursorpos = cursorpos;
792
793         return 0;                                       /* return value does not matter */
794 }
795
796 /*
797  * internalerrposition --- add internal cursor position to the current error
798  */
799 int
800 internalerrposition(int cursorpos)
801 {
802         ErrorData  *edata = &errordata[errordata_stack_depth];
803
804         /* we don't bother incrementing recursion_depth */
805         CHECK_STACK_DEPTH();
806
807         edata->internalpos = cursorpos;
808
809         return 0;                                       /* return value does not matter */
810 }
811
812 /*
813  * internalerrquery --- add internal query text to the current error
814  *
815  * Can also pass NULL to drop the internal query text entry.  This case
816  * is intended for use in error callback subroutines that are editorializing
817  * on the layout of the error report.
818  */
819 int
820 internalerrquery(const char *query)
821 {
822         ErrorData  *edata = &errordata[errordata_stack_depth];
823
824         /* we don't bother incrementing recursion_depth */
825         CHECK_STACK_DEPTH();
826
827         if (edata->internalquery)
828         {
829                 pfree(edata->internalquery);
830                 edata->internalquery = NULL;
831         }
832
833         if (query)
834                 edata->internalquery = MemoryContextStrdup(ErrorContext, query);
835
836         return 0;                                       /* return value does not matter */
837 }
838
839 /*
840  * geterrposition --- return the currently set error position (0 if none)
841  *
842  * This is only intended for use in error callback subroutines, since there
843  * is no other place outside elog.c where the concept is meaningful.
844  */
845 int
846 geterrposition(void)
847 {
848         ErrorData  *edata = &errordata[errordata_stack_depth];
849
850         /* we don't bother incrementing recursion_depth */
851         CHECK_STACK_DEPTH();
852
853         return edata->cursorpos;
854 }
855
856 /*
857  * getinternalerrposition --- same for internal error position
858  *
859  * This is only intended for use in error callback subroutines, since there
860  * is no other place outside elog.c where the concept is meaningful.
861  */
862 int
863 getinternalerrposition(void)
864 {
865         ErrorData  *edata = &errordata[errordata_stack_depth];
866
867         /* we don't bother incrementing recursion_depth */
868         CHECK_STACK_DEPTH();
869
870         return edata->internalpos;
871 }
872
873
874 /*
875  * elog_start --- startup for old-style API
876  *
877  * All that we do here is stash the hidden filename/lineno/funcname
878  * arguments into a stack entry.
879  *
880  * We need this to be separate from elog_finish because there's no other
881  * portable way to deal with inserting extra arguments into the elog call.
882  * (If macros with variable numbers of arguments were portable, it'd be
883  * easy, but they aren't.)
884  */
885 void
886 elog_start(const char *filename, int lineno, const char *funcname)
887 {
888         ErrorData  *edata;
889
890         if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
891         {
892                 /*
893                  * Wups, stack not big enough.  We treat this as a PANIC condition
894                  * because it suggests an infinite loop of errors during error
895                  * recovery.
896                  */
897                 errordata_stack_depth = -1;             /* make room on stack */
898                 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
899         }
900
901         edata = &errordata[errordata_stack_depth];
902         edata->filename = filename;
903         edata->lineno = lineno;
904         edata->funcname = funcname;
905         /* errno is saved now so that error parameter eval can't change it */
906         edata->saved_errno = errno;
907 }
908
909 /*
910  * elog_finish --- finish up for old-style API
911  */
912 void
913 elog_finish(int elevel, const char *fmt,...)
914 {
915         ErrorData  *edata = &errordata[errordata_stack_depth];
916         MemoryContext oldcontext;
917
918         CHECK_STACK_DEPTH();
919
920         /*
921          * Do errstart() to see if we actually want to report the message.
922          */
923         errordata_stack_depth--;
924         errno = edata->saved_errno;
925         if (!errstart(elevel, edata->filename, edata->lineno, edata->funcname))
926                 return;                                 /* nothing to do */
927
928         /*
929          * Format error message just like errmsg().
930          */
931         recursion_depth++;
932         oldcontext = MemoryContextSwitchTo(ErrorContext);
933
934         EVALUATE_MESSAGE(message, false);
935
936         MemoryContextSwitchTo(oldcontext);
937         recursion_depth--;
938
939         /*
940          * And let errfinish() finish up.
941          */
942         errfinish(0);
943 }
944
945 /*
946  * Actual output of the top-of-stack error message
947  *
948  * In the ereport(ERROR) case this is called from PostgresMain (or not at all,
949  * if the error is caught by somebody).  For all other severity levels this
950  * is called by errfinish.
951  */
952 void
953 EmitErrorReport(void)
954 {
955         ErrorData  *edata = &errordata[errordata_stack_depth];
956         MemoryContext oldcontext;
957
958         recursion_depth++;
959         CHECK_STACK_DEPTH();
960         oldcontext = MemoryContextSwitchTo(ErrorContext);
961
962         /* Send to server log, if enabled */
963         if (edata->output_to_server)
964                 send_message_to_server_log(edata);
965
966         /* Send to client, if enabled */
967         if (edata->output_to_client)
968                 send_message_to_frontend(edata);
969
970         MemoryContextSwitchTo(oldcontext);
971         recursion_depth--;
972 }
973
974 /*
975  * CopyErrorData --- obtain a copy of the topmost error stack entry
976  *
977  * This is only for use in error handler code.  The data is copied into the
978  * current memory context, so callers should always switch away from
979  * ErrorContext first; otherwise it will be lost when FlushErrorState is done.
980  */
981 ErrorData *
982 CopyErrorData(void)
983 {
984         ErrorData  *edata = &errordata[errordata_stack_depth];
985         ErrorData  *newedata;
986
987         /*
988          * we don't increment recursion_depth because out-of-memory here does not
989          * indicate a problem within the error subsystem.
990          */
991         CHECK_STACK_DEPTH();
992
993         Assert(CurrentMemoryContext != ErrorContext);
994
995         /* Copy the struct itself */
996         newedata = (ErrorData *) palloc(sizeof(ErrorData));
997         memcpy(newedata, edata, sizeof(ErrorData));
998
999         /* Make copies of separately-allocated fields */
1000         if (newedata->message)
1001                 newedata->message = pstrdup(newedata->message);
1002         if (newedata->detail)
1003                 newedata->detail = pstrdup(newedata->detail);
1004         if (newedata->hint)
1005                 newedata->hint = pstrdup(newedata->hint);
1006         if (newedata->context)
1007                 newedata->context = pstrdup(newedata->context);
1008         if (newedata->internalquery)
1009                 newedata->internalquery = pstrdup(newedata->internalquery);
1010
1011         return newedata;
1012 }
1013
1014 /*
1015  * FreeErrorData --- free the structure returned by CopyErrorData.
1016  *
1017  * Error handlers should use this in preference to assuming they know all
1018  * the separately-allocated fields.
1019  */
1020 void
1021 FreeErrorData(ErrorData *edata)
1022 {
1023         if (edata->message)
1024                 pfree(edata->message);
1025         if (edata->detail)
1026                 pfree(edata->detail);
1027         if (edata->hint)
1028                 pfree(edata->hint);
1029         if (edata->context)
1030                 pfree(edata->context);
1031         if (edata->internalquery)
1032                 pfree(edata->internalquery);
1033         pfree(edata);
1034 }
1035
1036 /*
1037  * FlushErrorState --- flush the error state after error recovery
1038  *
1039  * This should be called by an error handler after it's done processing
1040  * the error; or as soon as it's done CopyErrorData, if it intends to
1041  * do stuff that is likely to provoke another error.  You are not "out" of
1042  * the error subsystem until you have done this.
1043  */
1044 void
1045 FlushErrorState(void)
1046 {
1047         /*
1048          * Reset stack to empty.  The only case where it would be more than one
1049          * deep is if we serviced an error that interrupted construction of
1050          * another message.  We assume control escaped out of that message
1051          * construction and won't ever go back.
1052          */
1053         errordata_stack_depth = -1;
1054         recursion_depth = 0;
1055         /* Delete all data in ErrorContext */
1056         MemoryContextResetAndDeleteChildren(ErrorContext);
1057 }
1058
1059 /*
1060  * ReThrowError --- re-throw a previously copied error
1061  *
1062  * A handler can do CopyErrorData/FlushErrorState to get out of the error
1063  * subsystem, then do some processing, and finally ReThrowError to re-throw
1064  * the original error.  This is slower than just PG_RE_THROW() but should
1065  * be used if the "some processing" is likely to incur another error.
1066  */
1067 void
1068 ReThrowError(ErrorData *edata)
1069 {
1070         ErrorData  *newedata;
1071
1072         Assert(edata->elevel == ERROR);
1073
1074         /* Push the data back into the error context */
1075         recursion_depth++;
1076         MemoryContextSwitchTo(ErrorContext);
1077
1078         if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
1079         {
1080                 /*
1081                  * Wups, stack not big enough.  We treat this as a PANIC condition
1082                  * because it suggests an infinite loop of errors during error
1083                  * recovery.
1084                  */
1085                 errordata_stack_depth = -1;             /* make room on stack */
1086                 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
1087         }
1088
1089         newedata = &errordata[errordata_stack_depth];
1090         memcpy(newedata, edata, sizeof(ErrorData));
1091
1092         /* Make copies of separately-allocated fields */
1093         if (newedata->message)
1094                 newedata->message = pstrdup(newedata->message);
1095         if (newedata->detail)
1096                 newedata->detail = pstrdup(newedata->detail);
1097         if (newedata->hint)
1098                 newedata->hint = pstrdup(newedata->hint);
1099         if (newedata->context)
1100                 newedata->context = pstrdup(newedata->context);
1101         if (newedata->internalquery)
1102                 newedata->internalquery = pstrdup(newedata->internalquery);
1103
1104         recursion_depth--;
1105         PG_RE_THROW();
1106 }
1107
1108 /*
1109  * pg_re_throw --- out-of-line implementation of PG_RE_THROW() macro
1110  */
1111 void
1112 pg_re_throw(void)
1113 {
1114         /* If possible, throw the error to the next outer setjmp handler */
1115         if (PG_exception_stack != NULL)
1116                 siglongjmp(*PG_exception_stack, 1);
1117         else
1118         {
1119                 /*
1120                  * If we get here, elog(ERROR) was thrown inside a PG_TRY block, which
1121                  * we have now exited only to discover that there is no outer setjmp
1122                  * handler to pass the error to.  Had the error been thrown outside the
1123                  * block to begin with, we'd have promoted the error to FATAL, so the
1124                  * correct behavior is to make it FATAL now; that is, emit it and then
1125                  * call proc_exit.
1126                  */
1127                 ErrorData  *edata = &errordata[errordata_stack_depth];
1128
1129                 Assert(errordata_stack_depth >= 0);
1130                 Assert(edata->elevel == ERROR);
1131                 edata->elevel = FATAL;
1132
1133                 /*
1134                  * At least in principle, the increase in severity could have changed
1135                  * where-to-output decisions, so recalculate.  This should stay in
1136                  * sync with errstart(), which see for comments.
1137                  */
1138                 if (IsPostmasterEnvironment)
1139                         edata->output_to_server = is_log_level_output(FATAL,
1140                                                                                                                   log_min_messages);
1141                 else
1142                         edata->output_to_server = (FATAL >= log_min_messages);
1143                 if (whereToSendOutput == DestRemote)
1144                 {
1145                         if (ClientAuthInProgress)
1146                                 edata->output_to_client = true;
1147                         else
1148                                 edata->output_to_client = (FATAL >= client_min_messages);
1149                 }
1150
1151                 /*
1152                  * We can use errfinish() for the rest, but we don't want it to call
1153                  * any error context routines a second time.  Since we know we are
1154                  * about to exit, it should be OK to just clear the context stack.
1155                  */
1156                 error_context_stack = NULL;
1157
1158                 errfinish(0);
1159         }
1160
1161         /* We mustn't return... */
1162         ExceptionalCondition("pg_re_throw tried to return", "FailedAssertion",
1163                                                  __FILE__, __LINE__);
1164
1165         /*
1166          * Since ExceptionalCondition isn't declared noreturn because of
1167          * TrapMacro(), we need this to keep gcc from complaining.
1168          */
1169         abort();
1170 }
1171
1172
1173 /*
1174  * Initialization of error output file
1175  */
1176 void
1177 DebugFileOpen(void)
1178 {
1179         int                     fd,
1180                                 istty;
1181
1182         if (OutputFileName[0])
1183         {
1184                 /*
1185                  * A debug-output file name was given.
1186                  *
1187                  * Make sure we can write the file, and find out if it's a tty.
1188                  */
1189                 if ((fd = open(OutputFileName, O_CREAT | O_APPEND | O_WRONLY,
1190                                            0666)) < 0)
1191                         ereport(FATAL,
1192                                         (errcode_for_file_access(),
1193                                   errmsg("could not open file \"%s\": %m", OutputFileName)));
1194                 istty = isatty(fd);
1195                 close(fd);
1196
1197                 /*
1198                  * Redirect our stderr to the debug output file.
1199                  */
1200                 if (!freopen(OutputFileName, "a", stderr))
1201                         ereport(FATAL,
1202                                         (errcode_for_file_access(),
1203                                          errmsg("could not reopen file \"%s\" as stderr: %m",
1204                                                         OutputFileName)));
1205
1206                 /*
1207                  * If the file is a tty and we're running under the postmaster, try to
1208                  * send stdout there as well (if it isn't a tty then stderr will block
1209                  * out stdout, so we may as well let stdout go wherever it was going
1210                  * before).
1211                  */
1212                 if (istty && IsUnderPostmaster)
1213                         if (!freopen(OutputFileName, "a", stdout))
1214                                 ereport(FATAL,
1215                                                 (errcode_for_file_access(),
1216                                                  errmsg("could not reopen file \"%s\" as stdout: %m",
1217                                                                 OutputFileName)));
1218         }
1219 }
1220
1221
1222
1223 #ifdef HAVE_SYSLOG
1224
1225 /*
1226  * Set or update the parameters for syslog logging
1227  */
1228 void
1229 set_syslog_parameters(const char *ident, int facility)
1230 {
1231         /*
1232          * guc.c is likely to call us repeatedly with same parameters, so don't
1233          * thrash the syslog connection unnecessarily.  Also, we do not re-open
1234          * the connection until needed, since this routine will get called whether
1235          * or not Log_destination actually mentions syslog.
1236          *
1237          * Note that we make our own copy of the ident string rather than relying
1238          * on guc.c's.  This may be overly paranoid, but it ensures that we cannot
1239          * accidentally free a string that syslog is still using.
1240          */
1241         if (syslog_ident == NULL || strcmp(syslog_ident, ident) != 0 ||
1242                 syslog_facility != facility)
1243         {
1244                 if (openlog_done)
1245                 {
1246                         closelog();
1247                         openlog_done = false;
1248                 }
1249                 if (syslog_ident)
1250                         free(syslog_ident);
1251                 syslog_ident = strdup(ident);
1252                 /* if the strdup fails, we will cope in write_syslog() */
1253                 syslog_facility = facility;
1254         }
1255 }
1256
1257
1258 #ifndef PG_SYSLOG_LIMIT
1259 #define PG_SYSLOG_LIMIT 128
1260 #endif
1261
1262 /*
1263  * Write a message line to syslog
1264  */
1265 static void
1266 write_syslog(int level, const char *line)
1267 {
1268         static unsigned long seq = 0;
1269
1270         int                     len;
1271
1272         /* Open syslog connection if not done yet */
1273         if (!openlog_done)
1274         {
1275                 openlog(syslog_ident ? syslog_ident : "postgres",
1276                                 LOG_PID | LOG_NDELAY | LOG_NOWAIT,
1277                                 syslog_facility);
1278                 openlog_done = true;
1279         }
1280
1281         /*
1282          * We add a sequence number to each log message to suppress "same"
1283          * messages.
1284          */
1285         seq++;
1286
1287         /*
1288          * Our problem here is that many syslog implementations don't handle long
1289          * messages in an acceptable manner. While this function doesn't help that
1290          * fact, it does work around by splitting up messages into smaller pieces.
1291          *
1292          * We divide into multiple syslog() calls if message is too long or if the
1293          * message contains embedded NewLine(s) '\n'.
1294          */
1295         len = strlen(line);
1296         if (len > PG_SYSLOG_LIMIT || strchr(line, '\n') != NULL)
1297         {
1298                 int                     chunk_nr = 0;
1299
1300                 while (len > 0)
1301                 {
1302                         char            buf[PG_SYSLOG_LIMIT + 1];
1303                         const char *nlpos;
1304                         int                     buflen;
1305                         int                     i;
1306
1307                         /* if we start at a newline, move ahead one char */
1308                         if (line[0] == '\n')
1309                         {
1310                                 line++;
1311                                 len--;
1312                                 continue;
1313                         }
1314
1315                         /* copy one line, or as much as will fit, to buf */
1316                         nlpos = strchr(line, '\n');
1317                         if (nlpos != NULL)
1318                                 buflen = nlpos - line;
1319                         else
1320                                 buflen = len;
1321                         buflen = Min(buflen, PG_SYSLOG_LIMIT);
1322                         memcpy(buf, line, buflen);
1323                         buf[buflen] = '\0';
1324
1325                         /* trim to multibyte letter boundary */
1326                         buflen = pg_mbcliplen(buf, buflen, buflen);
1327                         if (buflen <= 0)
1328                                 return;
1329                         buf[buflen] = '\0';
1330
1331                         /* already word boundary? */
1332                         if (line[buflen] != '\0' &&
1333                                 !isspace((unsigned char) line[buflen]))
1334                         {
1335                                 /* try to divide at word boundary */
1336                                 i = buflen - 1;
1337                                 while (i > 0 && !isspace((unsigned char) buf[i]))
1338                                         i--;
1339
1340                                 if (i > 0)              /* else couldn't divide word boundary */
1341                                 {
1342                                         buflen = i;
1343                                         buf[i] = '\0';
1344                                 }
1345                         }
1346
1347                         chunk_nr++;
1348
1349                         syslog(level, "[%lu-%d] %s", seq, chunk_nr, buf);
1350                         line += buflen;
1351                         len -= buflen;
1352                 }
1353         }
1354         else
1355         {
1356                 /* message short enough */
1357                 syslog(level, "[%lu] %s", seq, line);
1358         }
1359 }
1360 #endif   /* HAVE_SYSLOG */
1361
1362 #ifdef WIN32
1363 /*
1364  * Write a message line to the windows event log
1365  */
1366 static void
1367 write_eventlog(int level, const char *line)
1368 {
1369         int                     eventlevel = EVENTLOG_ERROR_TYPE;
1370         static HANDLE evtHandle = INVALID_HANDLE_VALUE;
1371
1372         if (evtHandle == INVALID_HANDLE_VALUE)
1373         {
1374                 evtHandle = RegisterEventSource(NULL, "PostgreSQL");
1375                 if (evtHandle == NULL)
1376                 {
1377                         evtHandle = INVALID_HANDLE_VALUE;
1378                         return;
1379                 }
1380         }
1381
1382         switch (level)
1383         {
1384                 case DEBUG5:
1385                 case DEBUG4:
1386                 case DEBUG3:
1387                 case DEBUG2:
1388                 case DEBUG1:
1389                 case LOG:
1390                 case COMMERROR:
1391                 case INFO:
1392                 case NOTICE:
1393                         eventlevel = EVENTLOG_INFORMATION_TYPE;
1394                         break;
1395                 case WARNING:
1396                         eventlevel = EVENTLOG_WARNING_TYPE;
1397                         break;
1398                 case ERROR:
1399                 case FATAL:
1400                 case PANIC:
1401                 default:
1402                         eventlevel = EVENTLOG_ERROR_TYPE;
1403                         break;
1404         }
1405
1406
1407         ReportEvent(evtHandle,
1408                                 eventlevel,
1409                                 0,
1410                                 0,                              /* All events are Id 0 */
1411                                 NULL,
1412                                 1,
1413                                 0,
1414                                 &line,
1415                                 NULL);
1416 }
1417 #endif   /* WIN32 */
1418
1419 /*
1420  * Format tag info for log lines; append to the provided buffer.
1421  */
1422 static void
1423 log_line_prefix(StringInfo buf)
1424 {
1425         /* static counter for line numbers */
1426         static long log_line_number = 0;
1427
1428         /* has counter been reset in current process? */
1429         static int      log_my_pid = 0;
1430
1431         int                     format_len;
1432         int                     i;
1433
1434         /*
1435          * This is one of the few places where we'd rather not inherit a static
1436          * variable's value from the postmaster.  But since we will, reset it when
1437          * MyProcPid changes.
1438          */
1439         if (log_my_pid != MyProcPid)
1440         {
1441                 log_line_number = 0;
1442                 log_my_pid = MyProcPid;
1443         }
1444         log_line_number++;
1445
1446         if (Log_line_prefix == NULL)
1447                 return;                                 /* in case guc hasn't run yet */
1448
1449         format_len = strlen(Log_line_prefix);
1450
1451         for (i = 0; i < format_len; i++)
1452         {
1453                 if (Log_line_prefix[i] != '%')
1454                 {
1455                         /* literal char, just copy */
1456                         appendStringInfoChar(buf, Log_line_prefix[i]);
1457                         continue;
1458                 }
1459                 /* go to char after '%' */
1460                 i++;
1461                 if (i >= format_len)
1462                         break;                          /* format error - ignore it */
1463
1464                 /* process the option */
1465                 switch (Log_line_prefix[i])
1466                 {
1467                         case 'u':
1468                                 if (MyProcPort)
1469                                 {
1470                                         const char *username = MyProcPort->user_name;
1471
1472                                         if (username == NULL || *username == '\0')
1473                                                 username = _("[unknown]");
1474                                         appendStringInfo(buf, "%s", username);
1475                                 }
1476                                 break;
1477                         case 'd':
1478                                 if (MyProcPort)
1479                                 {
1480                                         const char *dbname = MyProcPort->database_name;
1481
1482                                         if (dbname == NULL || *dbname == '\0')
1483                                                 dbname = _("[unknown]");
1484                                         appendStringInfo(buf, "%s", dbname);
1485                                 }
1486                                 break;
1487                         case 'c':
1488                                 if (MyProcPort)
1489                                 {
1490                                         appendStringInfo(buf, "%lx.%x",
1491                                                                          (long) (MyProcPort->session_start),
1492                                                                          MyProcPid);
1493                                 }
1494                                 break;
1495                         case 'p':
1496                                 appendStringInfo(buf, "%d", MyProcPid);
1497                                 break;
1498                         case 'l':
1499                                 appendStringInfo(buf, "%ld", log_line_number);
1500                                 break;
1501                         case 'm':
1502                                 {
1503                                         /*
1504                                          * Note: for %m, %t, and %s we deliberately use the C
1505                                          * library's strftime/localtime, and not the equivalent
1506                                          * functions from src/timezone.  This ensures that all
1507                                          * backends will report log entries in the same timezone,
1508                                          * namely whatever C-library setting they inherit from the
1509                                          * postmaster.  If we used src/timezone then local
1510                                          * settings of the TimeZone GUC variable would confuse the
1511                                          * log.
1512                                          */
1513                                         time_t          stamp_time;
1514                                         char            strfbuf[128],
1515                                                                 msbuf[8];
1516                                         struct timeval tv;
1517
1518                                         gettimeofday(&tv, NULL);
1519                                         stamp_time = tv.tv_sec;
1520
1521                                         strftime(strfbuf, sizeof(strfbuf),
1522                                         /* leave room for milliseconds... */
1523                                         /* Win32 timezone names are too long so don't print them */
1524 #ifndef WIN32
1525                                                          "%Y-%m-%d %H:%M:%S     %Z",
1526 #else
1527                                                          "%Y-%m-%d %H:%M:%S     ",
1528 #endif
1529                                                          localtime(&stamp_time));
1530
1531                                         /* 'paste' milliseconds into place... */
1532                                         sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
1533                                         strncpy(strfbuf + 19, msbuf, 4);
1534
1535                                         appendStringInfoString(buf, strfbuf);
1536                                 }
1537                                 break;
1538                         case 't':
1539                                 {
1540                                         time_t          stamp_time = time(NULL);
1541                                         char            strfbuf[128];
1542
1543                                         strftime(strfbuf, sizeof(strfbuf),
1544                                         /* Win32 timezone names are too long so don't print them */
1545 #ifndef WIN32
1546                                                          "%Y-%m-%d %H:%M:%S %Z",
1547 #else
1548                                                          "%Y-%m-%d %H:%M:%S",
1549 #endif
1550                                                          localtime(&stamp_time));
1551                                         appendStringInfoString(buf, strfbuf);
1552                                 }
1553                                 break;
1554                         case 's':
1555                                 if (MyProcPort)
1556                                 {
1557                                         char            strfbuf[128];
1558
1559                                         strftime(strfbuf, sizeof(strfbuf),
1560                                         /* Win32 timezone names are too long so don't print them */
1561 #ifndef WIN32
1562                                                          "%Y-%m-%d %H:%M:%S %Z",
1563 #else
1564                                                          "%Y-%m-%d %H:%M:%S",
1565 #endif
1566                                                          localtime(&MyProcPort->session_start));
1567                                         appendStringInfoString(buf, strfbuf);
1568                                 }
1569                                 break;
1570                         case 'i':
1571                                 if (MyProcPort)
1572                                 {
1573                                         const char *psdisp;
1574                                         int                     displen;
1575
1576                                         psdisp = get_ps_display(&displen);
1577                                         appendStringInfo(buf, "%.*s", displen, psdisp);
1578                                 }
1579                                 break;
1580                         case 'r':
1581                                 if (MyProcPort && MyProcPort->remote_host)
1582                                 {
1583                                         appendStringInfo(buf, "%s", MyProcPort->remote_host);
1584                                         if (MyProcPort->remote_port &&
1585                                                 MyProcPort->remote_port[0] != '\0')
1586                                                 appendStringInfo(buf, "(%s)",
1587                                                                                  MyProcPort->remote_port);
1588                                 }
1589                                 break;
1590                         case 'h':
1591                                 if (MyProcPort && MyProcPort->remote_host)
1592                                         appendStringInfo(buf, "%s", MyProcPort->remote_host);
1593                                 break;
1594                         case 'q':
1595                                 /* in postmaster and friends, stop if %q is seen */
1596                                 /* in a backend, just ignore */
1597                                 if (MyProcPort == NULL)
1598                                         i = format_len;
1599                                 break;
1600                         case 'x':
1601                                 if (MyProcPort)
1602                                         appendStringInfo(buf, "%u", GetTopTransactionId());
1603                                 break;
1604                         case '%':
1605                                 appendStringInfoChar(buf, '%');
1606                                 break;
1607                         default:
1608                                 /* format error - ignore it */
1609                                 break;
1610                 }
1611         }
1612 }
1613
1614 /*
1615  * Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a
1616  * static buffer.
1617  */
1618 char *
1619 unpack_sql_state(int sql_state)
1620 {
1621         static char buf[12];
1622         int                     i;
1623
1624         for (i = 0; i < 5; i++)
1625         {
1626                 buf[i] = PGUNSIXBIT(sql_state);
1627                 sql_state >>= 6;
1628         }
1629
1630         buf[i] = '\0';
1631         return buf;
1632 }
1633
1634
1635 /*
1636  * Write error report to server's log
1637  */
1638 static void
1639 send_message_to_server_log(ErrorData *edata)
1640 {
1641         StringInfoData buf;
1642
1643         initStringInfo(&buf);
1644
1645         log_line_prefix(&buf);
1646         appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));
1647
1648         if (Log_error_verbosity >= PGERROR_VERBOSE)
1649                 appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode));
1650
1651         if (edata->message)
1652                 append_with_tabs(&buf, edata->message);
1653         else
1654                 append_with_tabs(&buf, _("missing error text"));
1655
1656         if (edata->cursorpos > 0)
1657                 appendStringInfo(&buf, _(" at character %d"),
1658                                                  edata->cursorpos);
1659         else if (edata->internalpos > 0)
1660                 appendStringInfo(&buf, _(" at character %d"),
1661                                                  edata->internalpos);
1662
1663         appendStringInfoChar(&buf, '\n');
1664
1665         if (Log_error_verbosity >= PGERROR_DEFAULT)
1666         {
1667                 if (edata->detail)
1668                 {
1669                         log_line_prefix(&buf);
1670                         appendStringInfoString(&buf, _("DETAIL:  "));
1671                         append_with_tabs(&buf, edata->detail);
1672                         appendStringInfoChar(&buf, '\n');
1673                 }
1674                 if (edata->hint)
1675                 {
1676                         log_line_prefix(&buf);
1677                         appendStringInfoString(&buf, _("HINT:  "));
1678                         append_with_tabs(&buf, edata->hint);
1679                         appendStringInfoChar(&buf, '\n');
1680                 }
1681                 if (edata->internalquery)
1682                 {
1683                         log_line_prefix(&buf);
1684                         appendStringInfoString(&buf, _("QUERY:  "));
1685                         append_with_tabs(&buf, edata->internalquery);
1686                         appendStringInfoChar(&buf, '\n');
1687                 }
1688                 if (edata->context)
1689                 {
1690                         log_line_prefix(&buf);
1691                         appendStringInfoString(&buf, _("CONTEXT:  "));
1692                         append_with_tabs(&buf, edata->context);
1693                         appendStringInfoChar(&buf, '\n');
1694                 }
1695                 if (Log_error_verbosity >= PGERROR_VERBOSE)
1696                 {
1697                         /* assume no newlines in funcname or filename... */
1698                         if (edata->funcname && edata->filename)
1699                         {
1700                                 log_line_prefix(&buf);
1701                                 appendStringInfo(&buf, _("LOCATION:  %s, %s:%d\n"),
1702                                                                  edata->funcname, edata->filename,
1703                                                                  edata->lineno);
1704                         }
1705                         else if (edata->filename)
1706                         {
1707                                 log_line_prefix(&buf);
1708                                 appendStringInfo(&buf, _("LOCATION:  %s:%d\n"),
1709                                                                  edata->filename, edata->lineno);
1710                         }
1711                 }
1712         }
1713
1714         /*
1715          * If the user wants the query that generated this error logged, do it.
1716          */
1717         if (is_log_level_output(edata->elevel, log_min_error_statement) &&
1718                 debug_query_string != NULL &&
1719                 !edata->hide_stmt)
1720         {
1721                 log_line_prefix(&buf);
1722                 appendStringInfoString(&buf, _("STATEMENT:  "));
1723                 append_with_tabs(&buf, debug_query_string);
1724                 appendStringInfoChar(&buf, '\n');
1725         }
1726
1727 #ifdef HAVE_SYSLOG
1728         /* Write to syslog, if enabled */
1729         if (Log_destination & LOG_DESTINATION_SYSLOG)
1730         {
1731                 int                     syslog_level;
1732
1733                 switch (edata->elevel)
1734                 {
1735                         case DEBUG5:
1736                         case DEBUG4:
1737                         case DEBUG3:
1738                         case DEBUG2:
1739                         case DEBUG1:
1740                                 syslog_level = LOG_DEBUG;
1741                                 break;
1742                         case LOG:
1743                         case COMMERROR:
1744                         case INFO:
1745                                 syslog_level = LOG_INFO;
1746                                 break;
1747                         case NOTICE:
1748                         case WARNING:
1749                                 syslog_level = LOG_NOTICE;
1750                                 break;
1751                         case ERROR:
1752                                 syslog_level = LOG_WARNING;
1753                                 break;
1754                         case FATAL:
1755                                 syslog_level = LOG_ERR;
1756                                 break;
1757                         case PANIC:
1758                         default:
1759                                 syslog_level = LOG_CRIT;
1760                                 break;
1761                 }
1762
1763                 write_syslog(syslog_level, buf.data);
1764         }
1765 #endif   /* HAVE_SYSLOG */
1766
1767 #ifdef WIN32
1768         /* Write to eventlog, if enabled */
1769         if (Log_destination & LOG_DESTINATION_EVENTLOG)
1770         {
1771                 write_eventlog(edata->elevel, buf.data);
1772         }
1773 #endif   /* WIN32 */
1774
1775         /* Write to stderr, if enabled */
1776         if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug)
1777         {
1778                 /*
1779                  * Use the chunking protocol if we know the syslogger should
1780                  * be catching stderr output, and we are not ourselves the
1781                  * syslogger.  Otherwise, just do a vanilla write to stderr.
1782                  */
1783                 if (redirection_done && !am_syslogger)
1784                         write_pipe_chunks(fileno(stderr), buf.data, buf.len);
1785 #ifdef WIN32
1786                 /*
1787                  * In a win32 service environment, there is no usable stderr. Capture
1788                  * anything going there and write it to the eventlog instead.
1789                  *
1790                  * If stderr redirection is active, it was OK to write to stderr above
1791                  * because that's really a pipe to the syslogger process.
1792                  */
1793                 else if (pgwin32_is_service())
1794                         write_eventlog(edata->elevel, buf.data);
1795 #endif
1796                 else
1797                         write(fileno(stderr), buf.data, buf.len);
1798         }
1799
1800         /* If in the syslogger process, try to write messages direct to file */
1801         if (am_syslogger)
1802                 write_syslogger_file(buf.data, buf.len);
1803
1804         pfree(buf.data);
1805 }
1806
1807 /*
1808  * Send data to the syslogger using the chunked protocol
1809  */
1810 static void
1811 write_pipe_chunks(int fd, char *data, int len)
1812 {
1813         PipeProtoChunk p;
1814
1815         Assert(len > 0);
1816
1817         p.proto.nuls[0] = p.proto.nuls[1] = '\0';
1818         p.proto.pid = MyProcPid;
1819
1820         /* write all but the last chunk */
1821         while (len > PIPE_MAX_PAYLOAD)
1822         {
1823                 p.proto.is_last = 'f';
1824                 p.proto.len = PIPE_MAX_PAYLOAD;
1825                 memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD);
1826                 write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD);
1827                 data += PIPE_MAX_PAYLOAD;
1828                 len -= PIPE_MAX_PAYLOAD;
1829         }
1830
1831         /* write the last chunk */
1832         p.proto.is_last = 't';
1833         p.proto.len = len;
1834         memcpy(p.proto.data, data, len);
1835         write(fd, &p, PIPE_HEADER_SIZE + len);
1836 }
1837
1838
1839 /*
1840  * Write error report to client
1841  */
1842 static void
1843 send_message_to_frontend(ErrorData *edata)
1844 {
1845         StringInfoData msgbuf;
1846
1847         /* 'N' (Notice) is for nonfatal conditions, 'E' is for errors */
1848         pq_beginmessage(&msgbuf, (edata->elevel < ERROR) ? 'N' : 'E');
1849
1850         if (PG_PROTOCOL_MAJOR(FrontendProtocol) >= 3)
1851         {
1852                 /* New style with separate fields */
1853                 char            tbuf[12];
1854                 int                     ssval;
1855                 int                     i;
1856
1857                 pq_sendbyte(&msgbuf, PG_DIAG_SEVERITY);
1858                 pq_sendstring(&msgbuf, error_severity(edata->elevel));
1859
1860                 /* unpack MAKE_SQLSTATE code */
1861                 ssval = edata->sqlerrcode;
1862                 for (i = 0; i < 5; i++)
1863                 {
1864                         tbuf[i] = PGUNSIXBIT(ssval);
1865                         ssval >>= 6;
1866                 }
1867                 tbuf[i] = '\0';
1868
1869                 pq_sendbyte(&msgbuf, PG_DIAG_SQLSTATE);
1870                 pq_sendstring(&msgbuf, tbuf);
1871
1872                 /* M field is required per protocol, so always send something */
1873                 pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_PRIMARY);
1874                 if (edata->message)
1875                         pq_sendstring(&msgbuf, edata->message);
1876                 else
1877                         pq_sendstring(&msgbuf, _("missing error text"));
1878
1879                 if (edata->detail)
1880                 {
1881                         pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_DETAIL);
1882                         pq_sendstring(&msgbuf, edata->detail);
1883                 }
1884
1885                 if (edata->hint)
1886                 {
1887                         pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_HINT);
1888                         pq_sendstring(&msgbuf, edata->hint);
1889                 }
1890
1891                 if (edata->context)
1892                 {
1893                         pq_sendbyte(&msgbuf, PG_DIAG_CONTEXT);
1894                         pq_sendstring(&msgbuf, edata->context);
1895                 }
1896
1897                 if (edata->cursorpos > 0)
1898                 {
1899                         snprintf(tbuf, sizeof(tbuf), "%d", edata->cursorpos);
1900                         pq_sendbyte(&msgbuf, PG_DIAG_STATEMENT_POSITION);
1901                         pq_sendstring(&msgbuf, tbuf);
1902                 }
1903
1904                 if (edata->internalpos > 0)
1905                 {
1906                         snprintf(tbuf, sizeof(tbuf), "%d", edata->internalpos);
1907                         pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_POSITION);
1908                         pq_sendstring(&msgbuf, tbuf);
1909                 }
1910
1911                 if (edata->internalquery)
1912                 {
1913                         pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_QUERY);
1914                         pq_sendstring(&msgbuf, edata->internalquery);
1915                 }
1916
1917                 if (edata->filename)
1918                 {
1919                         pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FILE);
1920                         pq_sendstring(&msgbuf, edata->filename);
1921                 }
1922
1923                 if (edata->lineno > 0)
1924                 {
1925                         snprintf(tbuf, sizeof(tbuf), "%d", edata->lineno);
1926                         pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_LINE);
1927                         pq_sendstring(&msgbuf, tbuf);
1928                 }
1929
1930                 if (edata->funcname)
1931                 {
1932                         pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FUNCTION);
1933                         pq_sendstring(&msgbuf, edata->funcname);
1934                 }
1935
1936                 pq_sendbyte(&msgbuf, '\0');             /* terminator */
1937         }
1938         else
1939         {
1940                 /* Old style --- gin up a backwards-compatible message */
1941                 StringInfoData buf;
1942
1943                 initStringInfo(&buf);
1944
1945                 appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));
1946
1947                 if (edata->show_funcname && edata->funcname)
1948                         appendStringInfo(&buf, "%s: ", edata->funcname);
1949
1950                 if (edata->message)
1951                         appendStringInfoString(&buf, edata->message);
1952                 else
1953                         appendStringInfoString(&buf, _("missing error text"));
1954
1955                 if (edata->cursorpos > 0)
1956                         appendStringInfo(&buf, _(" at character %d"),
1957                                                          edata->cursorpos);
1958                 else if (edata->internalpos > 0)
1959                         appendStringInfo(&buf, _(" at character %d"),
1960                                                          edata->internalpos);
1961
1962                 appendStringInfoChar(&buf, '\n');
1963
1964                 pq_sendstring(&msgbuf, buf.data);
1965
1966                 pfree(buf.data);
1967         }
1968
1969         pq_endmessage(&msgbuf);
1970
1971         /*
1972          * This flush is normally not necessary, since postgres.c will flush out
1973          * waiting data when control returns to the main loop. But it seems best
1974          * to leave it here, so that the client has some clue what happened if the
1975          * backend dies before getting back to the main loop ... error/notice
1976          * messages should not be a performance-critical path anyway, so an extra
1977          * flush won't hurt much ...
1978          */
1979         pq_flush();
1980 }
1981
1982
1983 /*
1984  * Support routines for formatting error messages.
1985  */
1986
1987
1988 /*
1989  * expand_fmt_string --- process special format codes in a format string
1990  *
1991  * We must replace %m with the appropriate strerror string, since vsnprintf
1992  * won't know what to do with it.
1993  *
1994  * The result is a palloc'd string.
1995  */
1996 static char *
1997 expand_fmt_string(const char *fmt, ErrorData *edata)
1998 {
1999         StringInfoData buf;
2000         const char *cp;
2001
2002         initStringInfo(&buf);
2003
2004         for (cp = fmt; *cp; cp++)
2005         {
2006                 if (cp[0] == '%' && cp[1] != '\0')
2007                 {
2008                         cp++;
2009                         if (*cp == 'm')
2010                         {
2011                                 /*
2012                                  * Replace %m by system error string.  If there are any %'s in
2013                                  * the string, we'd better double them so that vsnprintf won't
2014                                  * misinterpret.
2015                                  */
2016                                 const char *cp2;
2017
2018                                 cp2 = useful_strerror(edata->saved_errno);
2019                                 for (; *cp2; cp2++)
2020                                 {
2021                                         if (*cp2 == '%')
2022                                                 appendStringInfoCharMacro(&buf, '%');
2023                                         appendStringInfoCharMacro(&buf, *cp2);
2024                                 }
2025                         }
2026                         else
2027                         {
2028                                 /* copy % and next char --- this avoids trouble with %%m */
2029                                 appendStringInfoCharMacro(&buf, '%');
2030                                 appendStringInfoCharMacro(&buf, *cp);
2031                         }
2032                 }
2033                 else
2034                         appendStringInfoCharMacro(&buf, *cp);
2035         }
2036
2037         return buf.data;
2038 }
2039
2040
2041 /*
2042  * A slightly cleaned-up version of strerror()
2043  */
2044 static const char *
2045 useful_strerror(int errnum)
2046 {
2047         /* this buffer is only used if errno has a bogus value */
2048         static char errorstr_buf[48];
2049         const char *str;
2050
2051 #ifdef WIN32
2052         /* Winsock error code range, per WinError.h */
2053         if (errnum >= 10000 && errnum <= 11999)
2054                 return pgwin32_socket_strerror(errnum);
2055 #endif
2056         str = strerror(errnum);
2057
2058         /*
2059          * Some strerror()s return an empty string for out-of-range errno. This is
2060          * ANSI C spec compliant, but not exactly useful.
2061          */
2062         if (str == NULL || *str == '\0')
2063         {
2064                 snprintf(errorstr_buf, sizeof(errorstr_buf),
2065                                  /*------
2066                                    translator: This string will be truncated at 47
2067                                    characters expanded. */
2068                                  _("operating system error %d"), errnum);
2069                 str = errorstr_buf;
2070         }
2071
2072         return str;
2073 }
2074
2075
2076 /*
2077  * error_severity --- get localized string representing elevel
2078  */
2079 static const char *
2080 error_severity(int elevel)
2081 {
2082         const char *prefix;
2083
2084         switch (elevel)
2085         {
2086                 case DEBUG1:
2087                 case DEBUG2:
2088                 case DEBUG3:
2089                 case DEBUG4:
2090                 case DEBUG5:
2091                         prefix = _("DEBUG");
2092                         break;
2093                 case LOG:
2094                 case COMMERROR:
2095                         prefix = _("LOG");
2096                         break;
2097                 case INFO:
2098                         prefix = _("INFO");
2099                         break;
2100                 case NOTICE:
2101                         prefix = _("NOTICE");
2102                         break;
2103                 case WARNING:
2104                         prefix = _("WARNING");
2105                         break;
2106                 case ERROR:
2107                         prefix = _("ERROR");
2108                         break;
2109                 case FATAL:
2110                         prefix = _("FATAL");
2111                         break;
2112                 case PANIC:
2113                         prefix = _("PANIC");
2114                         break;
2115                 default:
2116                         prefix = "???";
2117                         break;
2118         }
2119
2120         return prefix;
2121 }
2122
2123
2124 /*
2125  *      append_with_tabs
2126  *
2127  *      Append the string to the StringInfo buffer, inserting a tab after any
2128  *      newline.
2129  */
2130 static void
2131 append_with_tabs(StringInfo buf, const char *str)
2132 {
2133         char            ch;
2134
2135         while ((ch = *str++) != '\0')
2136         {
2137                 appendStringInfoCharMacro(buf, ch);
2138                 if (ch == '\n')
2139                         appendStringInfoCharMacro(buf, '\t');
2140         }
2141 }
2142
2143
2144 /*
2145  * Write errors to stderr (or by equal means when stderr is
2146  * not available). Used before ereport/elog can be used
2147  * safely (memory context, GUC load etc)
2148  */
2149 void
2150 write_stderr(const char *fmt,...)
2151 {
2152         va_list         ap;
2153
2154         fmt = _(fmt);
2155
2156         va_start(ap, fmt);
2157 #ifndef WIN32
2158         /* On Unix, we just fprintf to stderr */
2159         vfprintf(stderr, fmt, ap);
2160         fflush(stderr);
2161 #else
2162
2163         /*
2164          * On Win32, we print to stderr if running on a console, or write to
2165          * eventlog if running as a service
2166          */
2167         if (pgwin32_is_service())       /* Running as a service */
2168         {
2169                 char            errbuf[2048];           /* Arbitrary size? */
2170
2171                 vsnprintf(errbuf, sizeof(errbuf), fmt, ap);
2172
2173                 write_eventlog(ERROR, errbuf);
2174         }
2175         else
2176         {
2177                 /* Not running as service, write to stderr */
2178                 vfprintf(stderr, fmt, ap);
2179                 fflush(stderr);
2180         }
2181 #endif
2182         va_end(ap);
2183 }
2184
2185
2186 /*
2187  * is_log_level_output -- is elevel logically >= log_min_level?
2188  *
2189  * We use this for tests that should consider LOG to sort out-of-order,
2190  * between ERROR and FATAL.  Generally this is the right thing for testing
2191  * whether a message should go to the postmaster log, whereas a simple >=
2192  * test is correct for testing whether the message should go to the client.
2193  */
2194 static bool
2195 is_log_level_output(int elevel, int log_min_level)
2196 {
2197         if (elevel == LOG || elevel == COMMERROR)
2198         {
2199                 if (log_min_level == LOG || log_min_level <= ERROR)
2200                         return true;
2201         }
2202         else if (log_min_level == LOG)
2203         {
2204                 /* elevel != LOG */
2205                 if (elevel >= FATAL)
2206                         return true;
2207         }
2208         /* Neither is LOG */
2209         else if (elevel >= log_min_level)
2210                 return true;
2211
2212         return false;
2213 }