1 /*-------------------------------------------------------------------------
2 *
3 * elog.c
4 * error logging and reporting
5 *
6 * Because of the extremely high rate at which log messages can be generated,
7 * we need to be mindful of the performance cost of obtaining any information
8 * that may be logged. Also, it's important to keep in mind that this code may
9 * get called from within an aborted transaction, in which case operations
10 * such as syscache lookups are unsafe.
11 *
12 * Some notes about recursion and errors during error processing:
13 *
14 * We need to be robust about recursive-error scenarios --- for example,
15 * if we run out of memory, it's important to be able to report that fact.
16 * There are a number of considerations that go into this.
17 *
18 * First, distinguish between re-entrant use and actual recursion. It
19 * is possible for an error or warning message to be emitted while the
20 * parameters for an error message are being computed. In this case
21 * errstart has been called for the outer message, and some field values
22 * may have already been saved, but we are not actually recursing. We handle
23 * this by providing a (small) stack of ErrorData records. The inner message
24 * can be computed and sent without disturbing the state of the outer message.
25 * (If the inner message is actually an error, this isn't very interesting
26 * because control won't come back to the outer message generator ... but
27 * if the inner message is only debug or log data, this is critical.)
28 *
29 * Second, actual recursion will occur if an error is reported by one of
30 * the elog.c routines or something they call. By far the most probable
31 * scenario of this sort is "out of memory"; and it's also the nastiest
32 * to handle because we'd likely also run out of memory while trying to
33 * report this error! Our escape hatch for this case is to reset the
34 * ErrorContext to empty before trying to process the inner error. Since
35 * ErrorContext is guaranteed to have at least 8K of space in it (see mcxt.c),
36 * we should be able to process an "out of memory" message successfully.
37 * Since we lose the prior error state due to the reset, we won't be able
38 * to return to processing the original error, but we wouldn't have anyway.
39 * (NOTE: the escape hatch is not used for recursive situations where the
40 * inner message is of less than ERROR severity; in that case we just
41 * try to process it and return normally. Usually this will work, but if
42 * it ends up in infinite recursion, we will PANIC due to error stack
43 * overflow.)
44 *
45 *
46 * Portions Copyright (c) 1996-2019, PostgreSQL Global Development Group
47 * Portions Copyright (c) 1994, Regents of the University of California
48 *
49 *
50 * IDENTIFICATION
51 * src/backend/utils/error/elog.c
52 *
53 *-------------------------------------------------------------------------
54 */
55 #include "postgres.h"
56
57 #include <fcntl.h>
58 #include <time.h>
59 #include <unistd.h>
60 #include <signal.h>
61 #include <ctype.h>
62 #ifdef HAVE_SYSLOG
63 #include <syslog.h>
64 #endif
65
66 #include "access/transam.h"
67 #include "access/xact.h"
68 #include "libpq/libpq.h"
69 #include "libpq/pqformat.h"
70 #include "mb/pg_wchar.h"
71 #include "miscadmin.h"
72 #include "postmaster/postmaster.h"
73 #include "postmaster/syslogger.h"
74 #include "storage/ipc.h"
75 #include "storage/proc.h"
76 #include "tcop/tcopprot.h"
77 #include "utils/guc.h"
78 #include "utils/memutils.h"
79 #include "utils/ps_status.h"
80
81
82 /* In this module, access gettext() via err_gettext() */
83 #undef _
84 #define _(x) err_gettext(x)
85
86
87 /* Global variables */
88 ErrorContextCallback *error_context_stack = NULL;
89
90 sigjmp_buf *PG_exception_stack = NULL;
91
92 extern bool redirection_done;
93
94 /*
95 * Hook for intercepting messages before they are sent to the server log.
96 * Note that the hook will not get called for messages that are suppressed
97 * by log_min_messages. Also note that logging hooks implemented in preload
98 * libraries will miss any log messages that are generated before the
99 * library is loaded.
100 */
101 emit_log_hook_type emit_log_hook = NULL;
102
103 /* GUC parameters */
104 int Log_error_verbosity = PGERROR_VERBOSE;
105 char *Log_line_prefix = NULL; /* format for extra log line info */
106 int Log_destination = LOG_DESTINATION_STDERR;
107 char *Log_destination_string = NULL;
108 bool syslog_sequence_numbers = true;
109 bool syslog_split_messages = true;
110
111 #ifdef HAVE_SYSLOG
112
113 /*
114 * Max string length to send to syslog(). Note that this doesn't count the
115 * sequence-number prefix we add, and of course it doesn't count the prefix
116 * added by syslog itself. Solaris and sysklogd truncate the final message
117 * at 1024 bytes, so this value leaves 124 bytes for those prefixes. (Most
118 * other syslog implementations seem to have limits of 2KB or so.)
119 */
120 #ifndef PG_SYSLOG_LIMIT
121 #define PG_SYSLOG_LIMIT 900
122 #endif
123
124 static bool openlog_done = false;
125 static char *syslog_ident = NULL;
126 static int syslog_facility = LOG_LOCAL0;
127
128 static void write_syslog(int level, const char *line);
129 #endif
130
131 #ifdef WIN32
132 extern char *event_source;
133
134 static void write_eventlog(int level, const char *line, int len);
135 #endif
136
137 /* We provide a small stack of ErrorData records for re-entrant cases */
138 #define ERRORDATA_STACK_SIZE 5
139
140 static ErrorData errordata[ERRORDATA_STACK_SIZE];
141
142 static int errordata_stack_depth = -1; /* index of topmost active frame */
143
144 static int recursion_depth = 0; /* to detect actual recursion */
145
146 /*
147 * Saved timeval and buffers for formatted timestamps that might be used by
148 * both log_line_prefix and csv logs.
149 */
150 static struct timeval saved_timeval;
151 static bool saved_timeval_set = false;
152
153 #define FORMATTED_TS_LEN 128
154 static char formatted_start_time[FORMATTED_TS_LEN];
155 static char formatted_log_time[FORMATTED_TS_LEN];
156
157
158 /* Macro for checking errordata_stack_depth is reasonable */
159 #define CHECK_STACK_DEPTH() \
160 do { \
161 if (errordata_stack_depth < 0) \
162 { \
163 errordata_stack_depth = -1; \
164 ereport(ERROR, (errmsg_internal("errstart was not called"))); \
165 } \
166 } while (0)
167
168
169 static const char *err_gettext(const char *str) pg_attribute_format_arg(1);
170 static void set_errdata_field(MemoryContextData *cxt, char **ptr, const char *str);
171 static void write_console(const char *line, int len);
172 static void setup_formatted_log_time(void);
173 static void setup_formatted_start_time(void);
174 static const char *process_log_prefix_padding(const char *p, int *padding);
175 static void log_line_prefix(StringInfo buf, ErrorData *edata);
176 static void write_csvlog(ErrorData *edata);
177 static void send_message_to_server_log(ErrorData *edata);
178 static void write_pipe_chunks(char *data, int len, int dest);
179 static void send_message_to_frontend(ErrorData *edata);
180 static const char *error_severity(int elevel);
181 static void append_with_tabs(StringInfo buf, const char *str);
182 static bool is_log_level_output(int elevel, int log_min_level);
183
184
185 /*
186 * in_error_recursion_trouble --- are we at risk of infinite error recursion?
187 *
188 * This function exists to provide common control of various fallback steps
189 * that we take if we think we are facing infinite error recursion. See the
190 * callers for details.
191 */
192 bool
in_error_recursion_trouble(void)193 in_error_recursion_trouble(void)
194 {
195 /* Pull the plug if recurse more than once */
196 return (recursion_depth > 2);
197 }
198
199 /*
200 * One of those fallback steps is to stop trying to localize the error
201 * message, since there's a significant probability that that's exactly
202 * what's causing the recursion.
203 */
204 static inline const char *
err_gettext(const char * str)205 err_gettext(const char *str)
206 {
207 #ifdef ENABLE_NLS
208 if (in_error_recursion_trouble())
209 return str;
210 else
211 return gettext(str);
212 #else
213 return str;
214 #endif
215 }
216
217
218 /*
219 * errstart --- begin an error-reporting cycle
220 *
221 * Create a stack entry and store the given parameters in it. Subsequently,
222 * errmsg() and perhaps other routines will be called to further populate
223 * the stack entry. Finally, errfinish() will be called to actually process
224 * the error report.
225 *
226 * Returns true in normal case. Returns false to short-circuit the error
227 * report (if it's a warning or lower and not to be reported anywhere).
228 */
229 bool
errstart(int elevel,const char * filename,int lineno,const char * funcname,const char * domain)230 errstart(int elevel, const char *filename, int lineno,
231 const char *funcname, const char *domain)
232 {
233 ErrorData *edata;
234 bool output_to_server;
235 bool output_to_client = false;
236 int i;
237
238 /*
239 * Check some cases in which we want to promote an error into a more
240 * severe error. None of this logic applies for non-error messages.
241 */
242 if (elevel >= ERROR)
243 {
244 /*
245 * If we are inside a critical section, all errors become PANIC
246 * errors. See miscadmin.h.
247 */
248 if (CritSectionCount > 0)
249 elevel = PANIC;
250
251 /*
252 * Check reasons for treating ERROR as FATAL:
253 *
254 * 1. we have no handler to pass the error to (implies we are in the
255 * postmaster or in backend startup).
256 *
257 * 2. ExitOnAnyError mode switch is set (initdb uses this).
258 *
259 * 3. the error occurred after proc_exit has begun to run. (It's
260 * proc_exit's responsibility to see that this doesn't turn into
261 * infinite recursion!)
262 */
263 if (elevel == ERROR)
264 {
265 if (PG_exception_stack == NULL ||
266 ExitOnAnyError ||
267 proc_exit_inprogress)
268 elevel = FATAL;
269 }
270
271 /*
272 * If the error level is ERROR or more, errfinish is not going to
273 * return to caller; therefore, if there is any stacked error already
274 * in progress it will be lost. This is more or less okay, except we
275 * do not want to have a FATAL or PANIC error downgraded because the
276 * reporting process was interrupted by a lower-grade error. So check
277 * the stack and make sure we panic if panic is warranted.
278 */
279 for (i = 0; i <= errordata_stack_depth; i++)
280 elevel = Max(elevel, errordata[i].elevel);
281 }
282
283 /*
284 * Now decide whether we need to process this report at all; if it's
285 * warning or less and not enabled for logging, just return false without
286 * starting up any error logging machinery.
287 */
288
289 /* Determine whether message is enabled for server log output */
290 output_to_server = is_log_level_output(elevel, log_min_messages);
291
292 /* Determine whether message is enabled for client output */
293 if (whereToSendOutput == DestRemote && elevel != LOG_SERVER_ONLY)
294 {
295 /*
296 * client_min_messages is honored only after we complete the
297 * authentication handshake. This is required both for security
298 * reasons and because many clients can't handle NOTICE messages
299 * during authentication.
300 */
301 if (ClientAuthInProgress)
302 output_to_client = (elevel >= ERROR);
303 else
304 output_to_client = (elevel >= client_min_messages ||
305 elevel == INFO);
306 }
307
308 /* Skip processing effort if non-error message will not be output */
309 if (elevel < ERROR && !output_to_server && !output_to_client)
310 return false;
311
312 /*
313 * We need to do some actual work. Make sure that memory context
314 * initialization has finished, else we can't do anything useful.
315 */
316 if (ErrorContext == NULL)
317 {
318 /* Oops, hard crash time; very little we can do safely here */
319 write_stderr("error occurred at %s:%d before error message processing is available\n",
320 filename ? filename : "(unknown file)", lineno);
321 exit(2);
322 }
323
324 /*
325 * Okay, crank up a stack entry to store the info in.
326 */
327
328 if (recursion_depth++ > 0 && elevel >= ERROR)
329 {
330 /*
331 * Oops, error during error processing. Clear ErrorContext as
332 * discussed at top of file. We will not return to the original
333 * error's reporter or handler, so we don't need it.
334 */
335 MemoryContextReset(ErrorContext);
336
337 /*
338 * Infinite error recursion might be due to something broken in a
339 * context traceback routine. Abandon them too. We also abandon
340 * attempting to print the error statement (which, if long, could
341 * itself be the source of the recursive failure).
342 */
343 if (in_error_recursion_trouble())
344 {
345 error_context_stack = NULL;
346 debug_query_string = NULL;
347 }
348 }
349 if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
350 {
351 /*
352 * Wups, stack not big enough. We treat this as a PANIC condition
353 * because it suggests an infinite loop of errors during error
354 * recovery.
355 */
356 errordata_stack_depth = -1; /* make room on stack */
357 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
358 }
359
360 /* Initialize data for this error frame */
361 edata = &errordata[errordata_stack_depth];
362 MemSet(edata, 0, sizeof(ErrorData));
363 edata->elevel = elevel;
364 edata->output_to_server = output_to_server;
365 edata->output_to_client = output_to_client;
366 if (filename)
367 {
368 const char *slash;
369
370 /* keep only base name, useful especially for vpath builds */
371 slash = strrchr(filename, '/');
372 if (slash)
373 filename = slash + 1;
374 }
375 edata->filename = filename;
376 edata->lineno = lineno;
377 edata->funcname = funcname;
378 /* the default text domain is the backend's */
379 edata->domain = domain ? domain : PG_TEXTDOMAIN("postgres");
380 /* initialize context_domain the same way (see set_errcontext_domain()) */
381 edata->context_domain = edata->domain;
382 /* Select default errcode based on elevel */
383 if (elevel >= ERROR)
384 edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
385 else if (elevel == WARNING)
386 edata->sqlerrcode = ERRCODE_WARNING;
387 else
388 edata->sqlerrcode = ERRCODE_SUCCESSFUL_COMPLETION;
389 /* errno is saved here so that error parameter eval can't change it */
390 edata->saved_errno = errno;
391
392 /*
393 * Any allocations for this error state level should go into ErrorContext
394 */
395 edata->assoc_context = ErrorContext;
396
397 recursion_depth--;
398 return true;
399 }
400
401 /*
402 * errfinish --- end an error-reporting cycle
403 *
404 * Produce the appropriate error report(s) and pop the error stack.
405 *
406 * If elevel is ERROR or worse, control does not return to the caller.
407 * See elog.h for the error level definitions.
408 */
409 void
errfinish(int dummy,...)410 errfinish(int dummy,...)
411 {
412 ErrorData *edata = &errordata[errordata_stack_depth];
413 int elevel;
414 MemoryContext oldcontext;
415 ErrorContextCallback *econtext;
416
417 recursion_depth++;
418 CHECK_STACK_DEPTH();
419 elevel = edata->elevel;
420
421 /*
422 * Do processing in ErrorContext, which we hope has enough reserved space
423 * to report an error.
424 */
425 oldcontext = MemoryContextSwitchTo(ErrorContext);
426
427 /*
428 * Call any context callback functions. Errors occurring in callback
429 * functions will be treated as recursive errors --- this ensures we will
430 * avoid infinite recursion (see errstart).
431 */
432 for (econtext = error_context_stack;
433 econtext != NULL;
434 econtext = econtext->previous)
435 econtext->callback(econtext->arg);
436
437 /*
438 * If ERROR (not more nor less) we pass it off to the current handler.
439 * Printing it and popping the stack is the responsibility of the handler.
440 */
441 if (elevel == ERROR)
442 {
443 /*
444 * We do some minimal cleanup before longjmp'ing so that handlers can
445 * execute in a reasonably sane state.
446 *
447 * Reset InterruptHoldoffCount in case we ereport'd from inside an
448 * interrupt holdoff section. (We assume here that no handler will
449 * itself be inside a holdoff section. If necessary, such a handler
450 * could save and restore InterruptHoldoffCount for itself, but this
451 * should make life easier for most.)
452 */
453 InterruptHoldoffCount = 0;
454 QueryCancelHoldoffCount = 0;
455
456 CritSectionCount = 0; /* should be unnecessary, but... */
457
458 /*
459 * Note that we leave CurrentMemoryContext set to ErrorContext. The
460 * handler should reset it to something else soon.
461 */
462
463 recursion_depth--;
464 PG_RE_THROW();
465 }
466
467 /*
468 * If we are doing FATAL or PANIC, abort any old-style COPY OUT in
469 * progress, so that we can report the message before dying. (Without
470 * this, pq_putmessage will refuse to send the message at all, which is
471 * what we want for NOTICE messages, but not for fatal exits.) This hack
472 * is necessary because of poor design of old-style copy protocol.
473 */
474 if (elevel >= FATAL && whereToSendOutput == DestRemote)
475 pq_endcopyout(true);
476
477 /* Emit the message to the right places */
478 EmitErrorReport();
479
480 /* Now free up subsidiary data attached to stack entry, and release it */
481 if (edata->message)
482 pfree(edata->message);
483 if (edata->detail)
484 pfree(edata->detail);
485 if (edata->detail_log)
486 pfree(edata->detail_log);
487 if (edata->hint)
488 pfree(edata->hint);
489 if (edata->context)
490 pfree(edata->context);
491 if (edata->schema_name)
492 pfree(edata->schema_name);
493 if (edata->table_name)
494 pfree(edata->table_name);
495 if (edata->column_name)
496 pfree(edata->column_name);
497 if (edata->datatype_name)
498 pfree(edata->datatype_name);
499 if (edata->constraint_name)
500 pfree(edata->constraint_name);
501 if (edata->internalquery)
502 pfree(edata->internalquery);
503
504 errordata_stack_depth--;
505
506 /* Exit error-handling context */
507 MemoryContextSwitchTo(oldcontext);
508 recursion_depth--;
509
510 /*
511 * Perform error recovery action as specified by elevel.
512 */
513 if (elevel == FATAL)
514 {
515 /*
516 * For a FATAL error, we let proc_exit clean up and exit.
517 *
518 * If we just reported a startup failure, the client will disconnect
519 * on receiving it, so don't send any more to the client.
520 */
521 if (PG_exception_stack == NULL && whereToSendOutput == DestRemote)
522 whereToSendOutput = DestNone;
523
524 /*
525 * fflush here is just to improve the odds that we get to see the
526 * error message, in case things are so hosed that proc_exit crashes.
527 * Any other code you might be tempted to add here should probably be
528 * in an on_proc_exit or on_shmem_exit callback instead.
529 */
530 fflush(stdout);
531 fflush(stderr);
532
533 /*
534 * Do normal process-exit cleanup, then return exit code 1 to indicate
535 * FATAL termination. The postmaster may or may not consider this
536 * worthy of panic, depending on which subprocess returns it.
537 */
538 proc_exit(1);
539 }
540
541 if (elevel >= PANIC)
542 {
543 /*
544 * Serious crash time. Postmaster will observe SIGABRT process exit
545 * status and kill the other backends too.
546 *
547 * XXX: what if we are *in* the postmaster? abort() won't kill our
548 * children...
549 */
550 fflush(stdout);
551 fflush(stderr);
552 abort();
553 }
554
555 /*
556 * Check for cancel/die interrupt first --- this is so that the user can
557 * stop a query emitting tons of notice or warning messages, even if it's
558 * in a loop that otherwise fails to check for interrupts.
559 */
560 CHECK_FOR_INTERRUPTS();
561 }
562
563
564 /*
565 * errcode --- add SQLSTATE error code to the current error
566 *
567 * The code is expected to be represented as per MAKE_SQLSTATE().
568 */
569 int
errcode(int sqlerrcode)570 errcode(int sqlerrcode)
571 {
572 ErrorData *edata = &errordata[errordata_stack_depth];
573
574 /* we don't bother incrementing recursion_depth */
575 CHECK_STACK_DEPTH();
576
577 edata->sqlerrcode = sqlerrcode;
578
579 return 0; /* return value does not matter */
580 }
581
582
583 /*
584 * errcode_for_file_access --- add SQLSTATE error code to the current error
585 *
586 * The SQLSTATE code is chosen based on the saved errno value. We assume
587 * that the failing operation was some type of disk file access.
588 *
589 * NOTE: the primary error message string should generally include %m
590 * when this is used.
591 */
592 int
errcode_for_file_access(void)593 errcode_for_file_access(void)
594 {
595 ErrorData *edata = &errordata[errordata_stack_depth];
596
597 /* we don't bother incrementing recursion_depth */
598 CHECK_STACK_DEPTH();
599
600 switch (edata->saved_errno)
601 {
602 /* Permission-denied failures */
603 case EPERM: /* Not super-user */
604 case EACCES: /* Permission denied */
605 #ifdef EROFS
606 case EROFS: /* Read only file system */
607 #endif
608 edata->sqlerrcode = ERRCODE_INSUFFICIENT_PRIVILEGE;
609 break;
610
611 /* File not found */
612 case ENOENT: /* No such file or directory */
613 edata->sqlerrcode = ERRCODE_UNDEFINED_FILE;
614 break;
615
616 /* Duplicate file */
617 case EEXIST: /* File exists */
618 edata->sqlerrcode = ERRCODE_DUPLICATE_FILE;
619 break;
620
621 /* Wrong object type or state */
622 case ENOTDIR: /* Not a directory */
623 case EISDIR: /* Is a directory */
624 #if defined(ENOTEMPTY) && (ENOTEMPTY != EEXIST) /* same code on AIX */
625 case ENOTEMPTY: /* Directory not empty */
626 #endif
627 edata->sqlerrcode = ERRCODE_WRONG_OBJECT_TYPE;
628 break;
629
630 /* Insufficient resources */
631 case ENOSPC: /* No space left on device */
632 edata->sqlerrcode = ERRCODE_DISK_FULL;
633 break;
634
635 case ENFILE: /* File table overflow */
636 case EMFILE: /* Too many open files */
637 edata->sqlerrcode = ERRCODE_INSUFFICIENT_RESOURCES;
638 break;
639
640 /* Hardware failure */
641 case EIO: /* I/O error */
642 edata->sqlerrcode = ERRCODE_IO_ERROR;
643 break;
644
645 /* All else is classified as internal errors */
646 default:
647 edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
648 break;
649 }
650
651 return 0; /* return value does not matter */
652 }
653
654 /*
655 * errcode_for_socket_access --- add SQLSTATE error code to the current error
656 *
657 * The SQLSTATE code is chosen based on the saved errno value. We assume
658 * that the failing operation was some type of socket access.
659 *
660 * NOTE: the primary error message string should generally include %m
661 * when this is used.
662 */
663 int
errcode_for_socket_access(void)664 errcode_for_socket_access(void)
665 {
666 ErrorData *edata = &errordata[errordata_stack_depth];
667
668 /* we don't bother incrementing recursion_depth */
669 CHECK_STACK_DEPTH();
670
671 switch (edata->saved_errno)
672 {
673 /* Loss of connection */
674 case EPIPE:
675 #ifdef ECONNRESET
676 case ECONNRESET:
677 #endif
678 edata->sqlerrcode = ERRCODE_CONNECTION_FAILURE;
679 break;
680
681 /* All else is classified as internal errors */
682 default:
683 edata->sqlerrcode = ERRCODE_INTERNAL_ERROR;
684 break;
685 }
686
687 return 0; /* return value does not matter */
688 }
689
690
691 /*
692 * This macro handles expansion of a format string and associated parameters;
693 * it's common code for errmsg(), errdetail(), etc. Must be called inside
694 * a routine that is declared like "const char *fmt, ..." and has an edata
695 * pointer set up. The message is assigned to edata->targetfield, or
696 * appended to it if appendval is true. The message is subject to translation
697 * if translateit is true.
698 *
699 * Note: we pstrdup the buffer rather than just transferring its storage
700 * to the edata field because the buffer might be considerably larger than
701 * really necessary.
702 */
703 #define EVALUATE_MESSAGE(domain, targetfield, appendval, translateit) \
704 { \
705 StringInfoData buf; \
706 /* Internationalize the error format string */ \
707 if ((translateit) && !in_error_recursion_trouble()) \
708 fmt = dgettext((domain), fmt); \
709 initStringInfo(&buf); \
710 if ((appendval) && edata->targetfield) { \
711 appendStringInfoString(&buf, edata->targetfield); \
712 appendStringInfoChar(&buf, '\n'); \
713 } \
714 /* Generate actual output --- have to use appendStringInfoVA */ \
715 for (;;) \
716 { \
717 va_list args; \
718 int needed; \
719 errno = edata->saved_errno; \
720 va_start(args, fmt); \
721 needed = appendStringInfoVA(&buf, fmt, args); \
722 va_end(args); \
723 if (needed == 0) \
724 break; \
725 enlargeStringInfo(&buf, needed); \
726 } \
727 /* Save the completed message into the stack item */ \
728 if (edata->targetfield) \
729 pfree(edata->targetfield); \
730 edata->targetfield = pstrdup(buf.data); \
731 pfree(buf.data); \
732 }
733
734 /*
735 * Same as above, except for pluralized error messages. The calling routine
736 * must be declared like "const char *fmt_singular, const char *fmt_plural,
737 * unsigned long n, ...". Translation is assumed always wanted.
738 */
739 #define EVALUATE_MESSAGE_PLURAL(domain, targetfield, appendval) \
740 { \
741 const char *fmt; \
742 StringInfoData buf; \
743 /* Internationalize the error format string */ \
744 if (!in_error_recursion_trouble()) \
745 fmt = dngettext((domain), fmt_singular, fmt_plural, n); \
746 else \
747 fmt = (n == 1 ? fmt_singular : fmt_plural); \
748 initStringInfo(&buf); \
749 if ((appendval) && edata->targetfield) { \
750 appendStringInfoString(&buf, edata->targetfield); \
751 appendStringInfoChar(&buf, '\n'); \
752 } \
753 /* Generate actual output --- have to use appendStringInfoVA */ \
754 for (;;) \
755 { \
756 va_list args; \
757 int needed; \
758 errno = edata->saved_errno; \
759 va_start(args, n); \
760 needed = appendStringInfoVA(&buf, fmt, args); \
761 va_end(args); \
762 if (needed == 0) \
763 break; \
764 enlargeStringInfo(&buf, needed); \
765 } \
766 /* Save the completed message into the stack item */ \
767 if (edata->targetfield) \
768 pfree(edata->targetfield); \
769 edata->targetfield = pstrdup(buf.data); \
770 pfree(buf.data); \
771 }
772
773
774 /*
775 * errmsg --- add a primary error message text to the current error
776 *
777 * In addition to the usual %-escapes recognized by printf, "%m" in
778 * fmt is replaced by the error message for the caller's value of errno.
779 *
780 * Note: no newline is needed at the end of the fmt string, since
781 * ereport will provide one for the output methods that need it.
782 */
783 int
errmsg(const char * fmt,...)784 errmsg(const char *fmt,...)
785 {
786 ErrorData *edata = &errordata[errordata_stack_depth];
787 MemoryContext oldcontext;
788
789 recursion_depth++;
790 CHECK_STACK_DEPTH();
791 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
792
793 edata->message_id = fmt;
794 EVALUATE_MESSAGE(edata->domain, message, false, true);
795
796 MemoryContextSwitchTo(oldcontext);
797 recursion_depth--;
798 return 0; /* return value does not matter */
799 }
800
801
802 /*
803 * errmsg_internal --- add a primary error message text to the current error
804 *
805 * This is exactly like errmsg() except that strings passed to errmsg_internal
806 * are not translated, and are customarily left out of the
807 * internationalization message dictionary. This should be used for "can't
808 * happen" cases that are probably not worth spending translation effort on.
809 * We also use this for certain cases where we *must* not try to translate
810 * the message because the translation would fail and result in infinite
811 * error recursion.
812 */
813 int
errmsg_internal(const char * fmt,...)814 errmsg_internal(const char *fmt,...)
815 {
816 ErrorData *edata = &errordata[errordata_stack_depth];
817 MemoryContext oldcontext;
818
819 recursion_depth++;
820 CHECK_STACK_DEPTH();
821 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
822
823 edata->message_id = fmt;
824 EVALUATE_MESSAGE(edata->domain, message, false, false);
825
826 MemoryContextSwitchTo(oldcontext);
827 recursion_depth--;
828 return 0; /* return value does not matter */
829 }
830
831
832 /*
833 * errmsg_plural --- add a primary error message text to the current error,
834 * with support for pluralization of the message text
835 */
836 int
errmsg_plural(const char * fmt_singular,const char * fmt_plural,unsigned long n,...)837 errmsg_plural(const char *fmt_singular, const char *fmt_plural,
838 unsigned long n,...)
839 {
840 ErrorData *edata = &errordata[errordata_stack_depth];
841 MemoryContext oldcontext;
842
843 recursion_depth++;
844 CHECK_STACK_DEPTH();
845 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
846
847 edata->message_id = fmt_singular;
848 EVALUATE_MESSAGE_PLURAL(edata->domain, message, false);
849
850 MemoryContextSwitchTo(oldcontext);
851 recursion_depth--;
852 return 0; /* return value does not matter */
853 }
854
855
856 /*
857 * errdetail --- add a detail error message text to the current error
858 */
859 int
errdetail(const char * fmt,...)860 errdetail(const char *fmt,...)
861 {
862 ErrorData *edata = &errordata[errordata_stack_depth];
863 MemoryContext oldcontext;
864
865 recursion_depth++;
866 CHECK_STACK_DEPTH();
867 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
868
869 EVALUATE_MESSAGE(edata->domain, detail, false, true);
870
871 MemoryContextSwitchTo(oldcontext);
872 recursion_depth--;
873 return 0; /* return value does not matter */
874 }
875
876
877 /*
878 * errdetail_internal --- add a detail error message text to the current error
879 *
880 * This is exactly like errdetail() except that strings passed to
881 * errdetail_internal are not translated, and are customarily left out of the
882 * internationalization message dictionary. This should be used for detail
883 * messages that seem not worth translating for one reason or another
884 * (typically, that they don't seem to be useful to average users).
885 */
886 int
errdetail_internal(const char * fmt,...)887 errdetail_internal(const char *fmt,...)
888 {
889 ErrorData *edata = &errordata[errordata_stack_depth];
890 MemoryContext oldcontext;
891
892 recursion_depth++;
893 CHECK_STACK_DEPTH();
894 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
895
896 EVALUATE_MESSAGE(edata->domain, detail, false, false);
897
898 MemoryContextSwitchTo(oldcontext);
899 recursion_depth--;
900 return 0; /* return value does not matter */
901 }
902
903
904 /*
905 * errdetail_log --- add a detail_log error message text to the current error
906 */
907 int
errdetail_log(const char * fmt,...)908 errdetail_log(const char *fmt,...)
909 {
910 ErrorData *edata = &errordata[errordata_stack_depth];
911 MemoryContext oldcontext;
912
913 recursion_depth++;
914 CHECK_STACK_DEPTH();
915 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
916
917 EVALUATE_MESSAGE(edata->domain, detail_log, false, true);
918
919 MemoryContextSwitchTo(oldcontext);
920 recursion_depth--;
921 return 0; /* return value does not matter */
922 }
923
924 /*
925 * errdetail_log_plural --- add a detail_log error message text to the current error
926 * with support for pluralization of the message text
927 */
928 int
errdetail_log_plural(const char * fmt_singular,const char * fmt_plural,unsigned long n,...)929 errdetail_log_plural(const char *fmt_singular, const char *fmt_plural,
930 unsigned long n,...)
931 {
932 ErrorData *edata = &errordata[errordata_stack_depth];
933 MemoryContext oldcontext;
934
935 recursion_depth++;
936 CHECK_STACK_DEPTH();
937 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
938
939 EVALUATE_MESSAGE_PLURAL(edata->domain, detail_log, false);
940
941 MemoryContextSwitchTo(oldcontext);
942 recursion_depth--;
943 return 0; /* return value does not matter */
944 }
945
946
947 /*
948 * errdetail_plural --- add a detail error message text to the current error,
949 * with support for pluralization of the message text
950 */
951 int
errdetail_plural(const char * fmt_singular,const char * fmt_plural,unsigned long n,...)952 errdetail_plural(const char *fmt_singular, const char *fmt_plural,
953 unsigned long n,...)
954 {
955 ErrorData *edata = &errordata[errordata_stack_depth];
956 MemoryContext oldcontext;
957
958 recursion_depth++;
959 CHECK_STACK_DEPTH();
960 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
961
962 EVALUATE_MESSAGE_PLURAL(edata->domain, detail, false);
963
964 MemoryContextSwitchTo(oldcontext);
965 recursion_depth--;
966 return 0; /* return value does not matter */
967 }
968
969
970 /*
971 * errhint --- add a hint error message text to the current error
972 */
973 int
errhint(const char * fmt,...)974 errhint(const char *fmt,...)
975 {
976 ErrorData *edata = &errordata[errordata_stack_depth];
977 MemoryContext oldcontext;
978
979 recursion_depth++;
980 CHECK_STACK_DEPTH();
981 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
982
983 EVALUATE_MESSAGE(edata->domain, hint, false, true);
984
985 MemoryContextSwitchTo(oldcontext);
986 recursion_depth--;
987 return 0; /* return value does not matter */
988 }
989
990
991 /*
992 * errcontext_msg --- add a context error message text to the current error
993 *
994 * Unlike other cases, multiple calls are allowed to build up a stack of
995 * context information. We assume earlier calls represent more-closely-nested
996 * states.
997 */
998 int
errcontext_msg(const char * fmt,...)999 errcontext_msg(const char *fmt,...)
1000 {
1001 ErrorData *edata = &errordata[errordata_stack_depth];
1002 MemoryContext oldcontext;
1003
1004 recursion_depth++;
1005 CHECK_STACK_DEPTH();
1006 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
1007
1008 EVALUATE_MESSAGE(edata->context_domain, context, true, true);
1009
1010 MemoryContextSwitchTo(oldcontext);
1011 recursion_depth--;
1012 return 0; /* return value does not matter */
1013 }
1014
1015 /*
1016 * set_errcontext_domain --- set message domain to be used by errcontext()
1017 *
1018 * errcontext_msg() can be called from a different module than the original
1019 * ereport(), so we cannot use the message domain passed in errstart() to
1020 * translate it. Instead, each errcontext_msg() call should be preceded by
1021 * a set_errcontext_domain() call to specify the domain. This is usually
1022 * done transparently by the errcontext() macro.
1023 */
1024 int
set_errcontext_domain(const char * domain)1025 set_errcontext_domain(const char *domain)
1026 {
1027 ErrorData *edata = &errordata[errordata_stack_depth];
1028
1029 /* we don't bother incrementing recursion_depth */
1030 CHECK_STACK_DEPTH();
1031
1032 /* the default text domain is the backend's */
1033 edata->context_domain = domain ? domain : PG_TEXTDOMAIN("postgres");
1034
1035 return 0; /* return value does not matter */
1036 }
1037
1038
1039 /*
1040 * errhidestmt --- optionally suppress STATEMENT: field of log entry
1041 *
1042 * This should be called if the message text already includes the statement.
1043 */
1044 int
errhidestmt(bool hide_stmt)1045 errhidestmt(bool hide_stmt)
1046 {
1047 ErrorData *edata = &errordata[errordata_stack_depth];
1048
1049 /* we don't bother incrementing recursion_depth */
1050 CHECK_STACK_DEPTH();
1051
1052 edata->hide_stmt = hide_stmt;
1053
1054 return 0; /* return value does not matter */
1055 }
1056
1057 /*
1058 * errhidecontext --- optionally suppress CONTEXT: field of log entry
1059 *
1060 * This should only be used for verbose debugging messages where the repeated
1061 * inclusion of context would bloat the log volume too much.
1062 */
1063 int
errhidecontext(bool hide_ctx)1064 errhidecontext(bool hide_ctx)
1065 {
1066 ErrorData *edata = &errordata[errordata_stack_depth];
1067
1068 /* we don't bother incrementing recursion_depth */
1069 CHECK_STACK_DEPTH();
1070
1071 edata->hide_ctx = hide_ctx;
1072
1073 return 0; /* return value does not matter */
1074 }
1075
1076
1077 /*
1078 * errfunction --- add reporting function name to the current error
1079 *
1080 * This is used when backwards compatibility demands that the function
1081 * name appear in messages sent to old-protocol clients. Note that the
1082 * passed string is expected to be a non-freeable constant string.
1083 */
1084 int
errfunction(const char * funcname)1085 errfunction(const char *funcname)
1086 {
1087 ErrorData *edata = &errordata[errordata_stack_depth];
1088
1089 /* we don't bother incrementing recursion_depth */
1090 CHECK_STACK_DEPTH();
1091
1092 edata->funcname = funcname;
1093 edata->show_funcname = true;
1094
1095 return 0; /* return value does not matter */
1096 }
1097
1098 /*
1099 * errposition --- add cursor position to the current error
1100 */
1101 int
errposition(int cursorpos)1102 errposition(int cursorpos)
1103 {
1104 ErrorData *edata = &errordata[errordata_stack_depth];
1105
1106 /* we don't bother incrementing recursion_depth */
1107 CHECK_STACK_DEPTH();
1108
1109 edata->cursorpos = cursorpos;
1110
1111 return 0; /* return value does not matter */
1112 }
1113
1114 /*
1115 * internalerrposition --- add internal cursor position to the current error
1116 */
1117 int
internalerrposition(int cursorpos)1118 internalerrposition(int cursorpos)
1119 {
1120 ErrorData *edata = &errordata[errordata_stack_depth];
1121
1122 /* we don't bother incrementing recursion_depth */
1123 CHECK_STACK_DEPTH();
1124
1125 edata->internalpos = cursorpos;
1126
1127 return 0; /* return value does not matter */
1128 }
1129
1130 /*
1131 * internalerrquery --- add internal query text to the current error
1132 *
1133 * Can also pass NULL to drop the internal query text entry. This case
1134 * is intended for use in error callback subroutines that are editorializing
1135 * on the layout of the error report.
1136 */
1137 int
internalerrquery(const char * query)1138 internalerrquery(const char *query)
1139 {
1140 ErrorData *edata = &errordata[errordata_stack_depth];
1141
1142 /* we don't bother incrementing recursion_depth */
1143 CHECK_STACK_DEPTH();
1144
1145 if (edata->internalquery)
1146 {
1147 pfree(edata->internalquery);
1148 edata->internalquery = NULL;
1149 }
1150
1151 if (query)
1152 edata->internalquery = MemoryContextStrdup(edata->assoc_context, query);
1153
1154 return 0; /* return value does not matter */
1155 }
1156
1157 /*
1158 * err_generic_string -- used to set individual ErrorData string fields
1159 * identified by PG_DIAG_xxx codes.
1160 *
1161 * This intentionally only supports fields that don't use localized strings,
1162 * so that there are no translation considerations.
1163 *
1164 * Most potential callers should not use this directly, but instead prefer
1165 * higher-level abstractions, such as errtablecol() (see relcache.c).
1166 */
1167 int
err_generic_string(int field,const char * str)1168 err_generic_string(int field, const char *str)
1169 {
1170 ErrorData *edata = &errordata[errordata_stack_depth];
1171
1172 /* we don't bother incrementing recursion_depth */
1173 CHECK_STACK_DEPTH();
1174
1175 switch (field)
1176 {
1177 case PG_DIAG_SCHEMA_NAME:
1178 set_errdata_field(edata->assoc_context, &edata->schema_name, str);
1179 break;
1180 case PG_DIAG_TABLE_NAME:
1181 set_errdata_field(edata->assoc_context, &edata->table_name, str);
1182 break;
1183 case PG_DIAG_COLUMN_NAME:
1184 set_errdata_field(edata->assoc_context, &edata->column_name, str);
1185 break;
1186 case PG_DIAG_DATATYPE_NAME:
1187 set_errdata_field(edata->assoc_context, &edata->datatype_name, str);
1188 break;
1189 case PG_DIAG_CONSTRAINT_NAME:
1190 set_errdata_field(edata->assoc_context, &edata->constraint_name, str);
1191 break;
1192 default:
1193 elog(ERROR, "unsupported ErrorData field id: %d", field);
1194 break;
1195 }
1196
1197 return 0; /* return value does not matter */
1198 }
1199
1200 /*
1201 * set_errdata_field --- set an ErrorData string field
1202 */
1203 static void
set_errdata_field(MemoryContextData * cxt,char ** ptr,const char * str)1204 set_errdata_field(MemoryContextData *cxt, char **ptr, const char *str)
1205 {
1206 Assert(*ptr == NULL);
1207 *ptr = MemoryContextStrdup(cxt, str);
1208 }
1209
1210 /*
1211 * geterrcode --- return the currently set SQLSTATE error code
1212 *
1213 * This is only intended for use in error callback subroutines, since there
1214 * is no other place outside elog.c where the concept is meaningful.
1215 */
1216 int
geterrcode(void)1217 geterrcode(void)
1218 {
1219 ErrorData *edata = &errordata[errordata_stack_depth];
1220
1221 /* we don't bother incrementing recursion_depth */
1222 CHECK_STACK_DEPTH();
1223
1224 return edata->sqlerrcode;
1225 }
1226
1227 /*
1228 * geterrposition --- return the currently set error position (0 if none)
1229 *
1230 * This is only intended for use in error callback subroutines, since there
1231 * is no other place outside elog.c where the concept is meaningful.
1232 */
1233 int
geterrposition(void)1234 geterrposition(void)
1235 {
1236 ErrorData *edata = &errordata[errordata_stack_depth];
1237
1238 /* we don't bother incrementing recursion_depth */
1239 CHECK_STACK_DEPTH();
1240
1241 return edata->cursorpos;
1242 }
1243
1244 /*
1245 * getinternalerrposition --- same for internal error position
1246 *
1247 * This is only intended for use in error callback subroutines, since there
1248 * is no other place outside elog.c where the concept is meaningful.
1249 */
1250 int
getinternalerrposition(void)1251 getinternalerrposition(void)
1252 {
1253 ErrorData *edata = &errordata[errordata_stack_depth];
1254
1255 /* we don't bother incrementing recursion_depth */
1256 CHECK_STACK_DEPTH();
1257
1258 return edata->internalpos;
1259 }
1260
1261
1262 /*
1263 * elog_start --- startup for old-style API
1264 *
1265 * All that we do here is stash the hidden filename/lineno/funcname
1266 * arguments into a stack entry, along with the current value of errno.
1267 *
1268 * We need this to be separate from elog_finish because there's no other
1269 * C89-compliant way to deal with inserting extra arguments into the elog
1270 * call. (When using C99's __VA_ARGS__, we could possibly merge this with
1271 * elog_finish, but there doesn't seem to be a good way to save errno before
1272 * evaluating the format arguments if we do that.)
1273 */
1274 void
elog_start(const char * filename,int lineno,const char * funcname)1275 elog_start(const char *filename, int lineno, const char *funcname)
1276 {
1277 ErrorData *edata;
1278
1279 /* Make sure that memory context initialization has finished */
1280 if (ErrorContext == NULL)
1281 {
1282 /* Oops, hard crash time; very little we can do safely here */
1283 write_stderr("error occurred at %s:%d before error message processing is available\n",
1284 filename ? filename : "(unknown file)", lineno);
1285 exit(2);
1286 }
1287
1288 if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
1289 {
1290 /*
1291 * Wups, stack not big enough. We treat this as a PANIC condition
1292 * because it suggests an infinite loop of errors during error
1293 * recovery. Note that the message is intentionally not localized,
1294 * else failure to convert it to client encoding could cause further
1295 * recursion.
1296 */
1297 errordata_stack_depth = -1; /* make room on stack */
1298 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
1299 }
1300
1301 edata = &errordata[errordata_stack_depth];
1302 if (filename)
1303 {
1304 const char *slash;
1305
1306 /* keep only base name, useful especially for vpath builds */
1307 slash = strrchr(filename, '/');
1308 if (slash)
1309 filename = slash + 1;
1310 }
1311 edata->filename = filename;
1312 edata->lineno = lineno;
1313 edata->funcname = funcname;
1314 /* errno is saved now so that error parameter eval can't change it */
1315 edata->saved_errno = errno;
1316
1317 /* Use ErrorContext for any allocations done at this level. */
1318 edata->assoc_context = ErrorContext;
1319 }
1320
1321 /*
1322 * elog_finish --- finish up for old-style API
1323 */
1324 void
elog_finish(int elevel,const char * fmt,...)1325 elog_finish(int elevel, const char *fmt,...)
1326 {
1327 ErrorData *edata = &errordata[errordata_stack_depth];
1328 MemoryContext oldcontext;
1329
1330 CHECK_STACK_DEPTH();
1331
1332 /*
1333 * Do errstart() to see if we actually want to report the message.
1334 */
1335 errordata_stack_depth--;
1336 errno = edata->saved_errno;
1337 if (!errstart(elevel, edata->filename, edata->lineno, edata->funcname, NULL))
1338 return; /* nothing to do */
1339
1340 /*
1341 * Format error message just like errmsg_internal().
1342 */
1343 recursion_depth++;
1344 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
1345
1346 edata->message_id = fmt;
1347 EVALUATE_MESSAGE(edata->domain, message, false, false);
1348
1349 MemoryContextSwitchTo(oldcontext);
1350 recursion_depth--;
1351
1352 /*
1353 * And let errfinish() finish up.
1354 */
1355 errfinish(0);
1356 }
1357
1358
1359 /*
1360 * Functions to allow construction of error message strings separately from
1361 * the ereport() call itself.
1362 *
1363 * The expected calling convention is
1364 *
1365 * pre_format_elog_string(errno, domain), var = format_elog_string(format,...)
1366 *
1367 * which can be hidden behind a macro such as GUC_check_errdetail(). We
1368 * assume that any functions called in the arguments of format_elog_string()
1369 * cannot result in re-entrant use of these functions --- otherwise the wrong
1370 * text domain might be used, or the wrong errno substituted for %m. This is
1371 * okay for the current usage with GUC check hooks, but might need further
1372 * effort someday.
1373 *
1374 * The result of format_elog_string() is stored in ErrorContext, and will
1375 * therefore survive until FlushErrorState() is called.
1376 */
1377 static int save_format_errnumber;
1378 static const char *save_format_domain;
1379
1380 void
pre_format_elog_string(int errnumber,const char * domain)1381 pre_format_elog_string(int errnumber, const char *domain)
1382 {
1383 /* Save errno before evaluation of argument functions can change it */
1384 save_format_errnumber = errnumber;
1385 /* Save caller's text domain */
1386 save_format_domain = domain;
1387 }
1388
1389 char *
format_elog_string(const char * fmt,...)1390 format_elog_string(const char *fmt,...)
1391 {
1392 ErrorData errdata;
1393 ErrorData *edata;
1394 MemoryContext oldcontext;
1395
1396 /* Initialize a mostly-dummy error frame */
1397 edata = &errdata;
1398 MemSet(edata, 0, sizeof(ErrorData));
1399 /* the default text domain is the backend's */
1400 edata->domain = save_format_domain ? save_format_domain : PG_TEXTDOMAIN("postgres");
1401 /* set the errno to be used to interpret %m */
1402 edata->saved_errno = save_format_errnumber;
1403
1404 oldcontext = MemoryContextSwitchTo(ErrorContext);
1405
1406 edata->message_id = fmt;
1407 EVALUATE_MESSAGE(edata->domain, message, false, true);
1408
1409 MemoryContextSwitchTo(oldcontext);
1410
1411 return edata->message;
1412 }
1413
1414
1415 /*
1416 * Actual output of the top-of-stack error message
1417 *
1418 * In the ereport(ERROR) case this is called from PostgresMain (or not at all,
1419 * if the error is caught by somebody). For all other severity levels this
1420 * is called by errfinish.
1421 */
1422 void
EmitErrorReport(void)1423 EmitErrorReport(void)
1424 {
1425 ErrorData *edata = &errordata[errordata_stack_depth];
1426 MemoryContext oldcontext;
1427
1428 recursion_depth++;
1429 CHECK_STACK_DEPTH();
1430 oldcontext = MemoryContextSwitchTo(edata->assoc_context);
1431
1432 /*
1433 * Call hook before sending message to log. The hook function is allowed
1434 * to turn off edata->output_to_server, so we must recheck that afterward.
1435 * Making any other change in the content of edata is not considered
1436 * supported.
1437 *
1438 * Note: the reason why the hook can only turn off output_to_server, and
1439 * not turn it on, is that it'd be unreliable: we will never get here at
1440 * all if errstart() deems the message uninteresting. A hook that could
1441 * make decisions in that direction would have to hook into errstart(),
1442 * where it would have much less information available. emit_log_hook is
1443 * intended for custom log filtering and custom log message transmission
1444 * mechanisms.
1445 *
1446 * The log hook has access to both the translated and original English
1447 * error message text, which is passed through to allow it to be used as a
1448 * message identifier. Note that the original text is not available for
1449 * detail, detail_log, hint and context text elements.
1450 */
1451 if (edata->output_to_server && emit_log_hook)
1452 (*emit_log_hook) (edata);
1453
1454 /* Send to server log, if enabled */
1455 if (edata->output_to_server)
1456 send_message_to_server_log(edata);
1457
1458 /* Send to client, if enabled */
1459 if (edata->output_to_client)
1460 send_message_to_frontend(edata);
1461
1462 MemoryContextSwitchTo(oldcontext);
1463 recursion_depth--;
1464 }
1465
1466 /*
1467 * CopyErrorData --- obtain a copy of the topmost error stack entry
1468 *
1469 * This is only for use in error handler code. The data is copied into the
1470 * current memory context, so callers should always switch away from
1471 * ErrorContext first; otherwise it will be lost when FlushErrorState is done.
1472 */
1473 ErrorData *
CopyErrorData(void)1474 CopyErrorData(void)
1475 {
1476 ErrorData *edata = &errordata[errordata_stack_depth];
1477 ErrorData *newedata;
1478
1479 /*
1480 * we don't increment recursion_depth because out-of-memory here does not
1481 * indicate a problem within the error subsystem.
1482 */
1483 CHECK_STACK_DEPTH();
1484
1485 Assert(CurrentMemoryContext != ErrorContext);
1486
1487 /* Copy the struct itself */
1488 newedata = (ErrorData *) palloc(sizeof(ErrorData));
1489 memcpy(newedata, edata, sizeof(ErrorData));
1490
1491 /* Make copies of separately-allocated fields */
1492 if (newedata->message)
1493 newedata->message = pstrdup(newedata->message);
1494 if (newedata->detail)
1495 newedata->detail = pstrdup(newedata->detail);
1496 if (newedata->detail_log)
1497 newedata->detail_log = pstrdup(newedata->detail_log);
1498 if (newedata->hint)
1499 newedata->hint = pstrdup(newedata->hint);
1500 if (newedata->context)
1501 newedata->context = pstrdup(newedata->context);
1502 if (newedata->schema_name)
1503 newedata->schema_name = pstrdup(newedata->schema_name);
1504 if (newedata->table_name)
1505 newedata->table_name = pstrdup(newedata->table_name);
1506 if (newedata->column_name)
1507 newedata->column_name = pstrdup(newedata->column_name);
1508 if (newedata->datatype_name)
1509 newedata->datatype_name = pstrdup(newedata->datatype_name);
1510 if (newedata->constraint_name)
1511 newedata->constraint_name = pstrdup(newedata->constraint_name);
1512 if (newedata->internalquery)
1513 newedata->internalquery = pstrdup(newedata->internalquery);
1514
1515 /* Use the calling context for string allocation */
1516 newedata->assoc_context = CurrentMemoryContext;
1517
1518 return newedata;
1519 }
1520
1521 /*
1522 * FreeErrorData --- free the structure returned by CopyErrorData.
1523 *
1524 * Error handlers should use this in preference to assuming they know all
1525 * the separately-allocated fields.
1526 */
1527 void
FreeErrorData(ErrorData * edata)1528 FreeErrorData(ErrorData *edata)
1529 {
1530 if (edata->message)
1531 pfree(edata->message);
1532 if (edata->detail)
1533 pfree(edata->detail);
1534 if (edata->detail_log)
1535 pfree(edata->detail_log);
1536 if (edata->hint)
1537 pfree(edata->hint);
1538 if (edata->context)
1539 pfree(edata->context);
1540 if (edata->schema_name)
1541 pfree(edata->schema_name);
1542 if (edata->table_name)
1543 pfree(edata->table_name);
1544 if (edata->column_name)
1545 pfree(edata->column_name);
1546 if (edata->datatype_name)
1547 pfree(edata->datatype_name);
1548 if (edata->constraint_name)
1549 pfree(edata->constraint_name);
1550 if (edata->internalquery)
1551 pfree(edata->internalquery);
1552 pfree(edata);
1553 }
1554
1555 /*
1556 * FlushErrorState --- flush the error state after error recovery
1557 *
1558 * This should be called by an error handler after it's done processing
1559 * the error; or as soon as it's done CopyErrorData, if it intends to
1560 * do stuff that is likely to provoke another error. You are not "out" of
1561 * the error subsystem until you have done this.
1562 */
1563 void
FlushErrorState(void)1564 FlushErrorState(void)
1565 {
1566 /*
1567 * Reset stack to empty. The only case where it would be more than one
1568 * deep is if we serviced an error that interrupted construction of
1569 * another message. We assume control escaped out of that message
1570 * construction and won't ever go back.
1571 */
1572 errordata_stack_depth = -1;
1573 recursion_depth = 0;
1574 /* Delete all data in ErrorContext */
1575 MemoryContextResetAndDeleteChildren(ErrorContext);
1576 }
1577
1578 /*
1579 * ThrowErrorData --- report an error described by an ErrorData structure
1580 *
1581 * This is somewhat like ReThrowError, but it allows elevels besides ERROR,
1582 * and the boolean flags such as output_to_server are computed via the
1583 * default rules rather than being copied from the given ErrorData.
1584 * This is primarily used to re-report errors originally reported by
1585 * background worker processes and then propagated (with or without
1586 * modification) to the backend responsible for them.
1587 */
1588 void
ThrowErrorData(ErrorData * edata)1589 ThrowErrorData(ErrorData *edata)
1590 {
1591 ErrorData *newedata;
1592 MemoryContext oldcontext;
1593
1594 if (!errstart(edata->elevel, edata->filename, edata->lineno,
1595 edata->funcname, NULL))
1596 return; /* error is not to be reported at all */
1597
1598 newedata = &errordata[errordata_stack_depth];
1599 recursion_depth++;
1600 oldcontext = MemoryContextSwitchTo(newedata->assoc_context);
1601
1602 /* Copy the supplied fields to the error stack entry. */
1603 if (edata->sqlerrcode != 0)
1604 newedata->sqlerrcode = edata->sqlerrcode;
1605 if (edata->message)
1606 newedata->message = pstrdup(edata->message);
1607 if (edata->detail)
1608 newedata->detail = pstrdup(edata->detail);
1609 if (edata->detail_log)
1610 newedata->detail_log = pstrdup(edata->detail_log);
1611 if (edata->hint)
1612 newedata->hint = pstrdup(edata->hint);
1613 if (edata->context)
1614 newedata->context = pstrdup(edata->context);
1615 /* assume message_id is not available */
1616 if (edata->schema_name)
1617 newedata->schema_name = pstrdup(edata->schema_name);
1618 if (edata->table_name)
1619 newedata->table_name = pstrdup(edata->table_name);
1620 if (edata->column_name)
1621 newedata->column_name = pstrdup(edata->column_name);
1622 if (edata->datatype_name)
1623 newedata->datatype_name = pstrdup(edata->datatype_name);
1624 if (edata->constraint_name)
1625 newedata->constraint_name = pstrdup(edata->constraint_name);
1626 newedata->cursorpos = edata->cursorpos;
1627 newedata->internalpos = edata->internalpos;
1628 if (edata->internalquery)
1629 newedata->internalquery = pstrdup(edata->internalquery);
1630
1631 MemoryContextSwitchTo(oldcontext);
1632 recursion_depth--;
1633
1634 /* Process the error. */
1635 errfinish(0);
1636 }
1637
1638 /*
1639 * ReThrowError --- re-throw a previously copied error
1640 *
1641 * A handler can do CopyErrorData/FlushErrorState to get out of the error
1642 * subsystem, then do some processing, and finally ReThrowError to re-throw
1643 * the original error. This is slower than just PG_RE_THROW() but should
1644 * be used if the "some processing" is likely to incur another error.
1645 */
1646 void
ReThrowError(ErrorData * edata)1647 ReThrowError(ErrorData *edata)
1648 {
1649 ErrorData *newedata;
1650
1651 Assert(edata->elevel == ERROR);
1652
1653 /* Push the data back into the error context */
1654 recursion_depth++;
1655 MemoryContextSwitchTo(ErrorContext);
1656
1657 if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
1658 {
1659 /*
1660 * Wups, stack not big enough. We treat this as a PANIC condition
1661 * because it suggests an infinite loop of errors during error
1662 * recovery.
1663 */
1664 errordata_stack_depth = -1; /* make room on stack */
1665 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
1666 }
1667
1668 newedata = &errordata[errordata_stack_depth];
1669 memcpy(newedata, edata, sizeof(ErrorData));
1670
1671 /* Make copies of separately-allocated fields */
1672 if (newedata->message)
1673 newedata->message = pstrdup(newedata->message);
1674 if (newedata->detail)
1675 newedata->detail = pstrdup(newedata->detail);
1676 if (newedata->detail_log)
1677 newedata->detail_log = pstrdup(newedata->detail_log);
1678 if (newedata->hint)
1679 newedata->hint = pstrdup(newedata->hint);
1680 if (newedata->context)
1681 newedata->context = pstrdup(newedata->context);
1682 if (newedata->schema_name)
1683 newedata->schema_name = pstrdup(newedata->schema_name);
1684 if (newedata->table_name)
1685 newedata->table_name = pstrdup(newedata->table_name);
1686 if (newedata->column_name)
1687 newedata->column_name = pstrdup(newedata->column_name);
1688 if (newedata->datatype_name)
1689 newedata->datatype_name = pstrdup(newedata->datatype_name);
1690 if (newedata->constraint_name)
1691 newedata->constraint_name = pstrdup(newedata->constraint_name);
1692 if (newedata->internalquery)
1693 newedata->internalquery = pstrdup(newedata->internalquery);
1694
1695 /* Reset the assoc_context to be ErrorContext */
1696 newedata->assoc_context = ErrorContext;
1697
1698 recursion_depth--;
1699 PG_RE_THROW();
1700 }
1701
1702 /*
1703 * pg_re_throw --- out-of-line implementation of PG_RE_THROW() macro
1704 */
1705 void
pg_re_throw(void)1706 pg_re_throw(void)
1707 {
1708 /* If possible, throw the error to the next outer setjmp handler */
1709 if (PG_exception_stack != NULL)
1710 siglongjmp(*PG_exception_stack, 1);
1711 else
1712 {
1713 /*
1714 * If we get here, elog(ERROR) was thrown inside a PG_TRY block, which
1715 * we have now exited only to discover that there is no outer setjmp
1716 * handler to pass the error to. Had the error been thrown outside
1717 * the block to begin with, we'd have promoted the error to FATAL, so
1718 * the correct behavior is to make it FATAL now; that is, emit it and
1719 * then call proc_exit.
1720 */
1721 ErrorData *edata = &errordata[errordata_stack_depth];
1722
1723 Assert(errordata_stack_depth >= 0);
1724 Assert(edata->elevel == ERROR);
1725 edata->elevel = FATAL;
1726
1727 /*
1728 * At least in principle, the increase in severity could have changed
1729 * where-to-output decisions, so recalculate. This should stay in
1730 * sync with errstart(), which see for comments.
1731 */
1732 if (IsPostmasterEnvironment)
1733 edata->output_to_server = is_log_level_output(FATAL,
1734 log_min_messages);
1735 else
1736 edata->output_to_server = (FATAL >= log_min_messages);
1737 if (whereToSendOutput == DestRemote)
1738 edata->output_to_client = true;
1739
1740 /*
1741 * We can use errfinish() for the rest, but we don't want it to call
1742 * any error context routines a second time. Since we know we are
1743 * about to exit, it should be OK to just clear the context stack.
1744 */
1745 error_context_stack = NULL;
1746
1747 errfinish(0);
1748 }
1749
1750 /* Doesn't return ... */
1751 ExceptionalCondition("pg_re_throw tried to return", "FailedAssertion",
1752 __FILE__, __LINE__);
1753 }
1754
1755
1756 /*
1757 * GetErrorContextStack - Return the context stack, for display/diags
1758 *
1759 * Returns a pstrdup'd string in the caller's context which includes the PG
1760 * error call stack. It is the caller's responsibility to ensure this string
1761 * is pfree'd (or its context cleaned up) when done.
1762 *
1763 * This information is collected by traversing the error contexts and calling
1764 * each context's callback function, each of which is expected to call
1765 * errcontext() to return a string which can be presented to the user.
1766 */
1767 char *
GetErrorContextStack(void)1768 GetErrorContextStack(void)
1769 {
1770 ErrorData *edata;
1771 ErrorContextCallback *econtext;
1772
1773 /*
1774 * Okay, crank up a stack entry to store the info in.
1775 */
1776 recursion_depth++;
1777
1778 if (++errordata_stack_depth >= ERRORDATA_STACK_SIZE)
1779 {
1780 /*
1781 * Wups, stack not big enough. We treat this as a PANIC condition
1782 * because it suggests an infinite loop of errors during error
1783 * recovery.
1784 */
1785 errordata_stack_depth = -1; /* make room on stack */
1786 ereport(PANIC, (errmsg_internal("ERRORDATA_STACK_SIZE exceeded")));
1787 }
1788
1789 /*
1790 * Things look good so far, so initialize our error frame
1791 */
1792 edata = &errordata[errordata_stack_depth];
1793 MemSet(edata, 0, sizeof(ErrorData));
1794
1795 /*
1796 * Set up assoc_context to be the caller's context, so any allocations
1797 * done (which will include edata->context) will use their context.
1798 */
1799 edata->assoc_context = CurrentMemoryContext;
1800
1801 /*
1802 * Call any context callback functions to collect the context information
1803 * into edata->context.
1804 *
1805 * Errors occurring in callback functions should go through the regular
1806 * error handling code which should handle any recursive errors, though we
1807 * double-check above, just in case.
1808 */
1809 for (econtext = error_context_stack;
1810 econtext != NULL;
1811 econtext = econtext->previous)
1812 econtext->callback(econtext->arg);
1813
1814 /*
1815 * Clean ourselves off the stack, any allocations done should have been
1816 * using edata->assoc_context, which we set up earlier to be the caller's
1817 * context, so we're free to just remove our entry off the stack and
1818 * decrement recursion depth and exit.
1819 */
1820 errordata_stack_depth--;
1821 recursion_depth--;
1822
1823 /*
1824 * Return a pointer to the string the caller asked for, which should have
1825 * been allocated in their context.
1826 */
1827 return edata->context;
1828 }
1829
1830
1831 /*
1832 * Initialization of error output file
1833 */
1834 void
DebugFileOpen(void)1835 DebugFileOpen(void)
1836 {
1837 int fd,
1838 istty;
1839
1840 if (OutputFileName[0])
1841 {
1842 /*
1843 * A debug-output file name was given.
1844 *
1845 * Make sure we can write the file, and find out if it's a tty.
1846 */
1847 if ((fd = open(OutputFileName, O_CREAT | O_APPEND | O_WRONLY,
1848 0666)) < 0)
1849 ereport(FATAL,
1850 (errcode_for_file_access(),
1851 errmsg("could not open file \"%s\": %m", OutputFileName)));
1852 istty = isatty(fd);
1853 close(fd);
1854
1855 /*
1856 * Redirect our stderr to the debug output file.
1857 */
1858 if (!freopen(OutputFileName, "a", stderr))
1859 ereport(FATAL,
1860 (errcode_for_file_access(),
1861 errmsg("could not reopen file \"%s\" as stderr: %m",
1862 OutputFileName)));
1863
1864 /*
1865 * If the file is a tty and we're running under the postmaster, try to
1866 * send stdout there as well (if it isn't a tty then stderr will block
1867 * out stdout, so we may as well let stdout go wherever it was going
1868 * before).
1869 */
1870 if (istty && IsUnderPostmaster)
1871 if (!freopen(OutputFileName, "a", stdout))
1872 ereport(FATAL,
1873 (errcode_for_file_access(),
1874 errmsg("could not reopen file \"%s\" as stdout: %m",
1875 OutputFileName)));
1876 }
1877 }
1878
1879
1880 #ifdef HAVE_SYSLOG
1881
1882 /*
1883 * Set or update the parameters for syslog logging
1884 */
1885 void
set_syslog_parameters(const char * ident,int facility)1886 set_syslog_parameters(const char *ident, int facility)
1887 {
1888 /*
1889 * guc.c is likely to call us repeatedly with same parameters, so don't
1890 * thrash the syslog connection unnecessarily. Also, we do not re-open
1891 * the connection until needed, since this routine will get called whether
1892 * or not Log_destination actually mentions syslog.
1893 *
1894 * Note that we make our own copy of the ident string rather than relying
1895 * on guc.c's. This may be overly paranoid, but it ensures that we cannot
1896 * accidentally free a string that syslog is still using.
1897 */
1898 if (syslog_ident == NULL || strcmp(syslog_ident, ident) != 0 ||
1899 syslog_facility != facility)
1900 {
1901 if (openlog_done)
1902 {
1903 closelog();
1904 openlog_done = false;
1905 }
1906 if (syslog_ident)
1907 free(syslog_ident);
1908 syslog_ident = strdup(ident);
1909 /* if the strdup fails, we will cope in write_syslog() */
1910 syslog_facility = facility;
1911 }
1912 }
1913
1914
1915 /*
1916 * Write a message line to syslog
1917 */
1918 static void
write_syslog(int level,const char * line)1919 write_syslog(int level, const char *line)
1920 {
1921 static unsigned long seq = 0;
1922
1923 int len;
1924 const char *nlpos;
1925
1926 /* Open syslog connection if not done yet */
1927 if (!openlog_done)
1928 {
1929 openlog(syslog_ident ? syslog_ident : "postgres",
1930 LOG_PID | LOG_NDELAY | LOG_NOWAIT,
1931 syslog_facility);
1932 openlog_done = true;
1933 }
1934
1935 /*
1936 * We add a sequence number to each log message to suppress "same"
1937 * messages.
1938 */
1939 seq++;
1940
1941 /*
1942 * Our problem here is that many syslog implementations don't handle long
1943 * messages in an acceptable manner. While this function doesn't help that
1944 * fact, it does work around by splitting up messages into smaller pieces.
1945 *
1946 * We divide into multiple syslog() calls if message is too long or if the
1947 * message contains embedded newline(s).
1948 */
1949 len = strlen(line);
1950 nlpos = strchr(line, '\n');
1951 if (syslog_split_messages && (len > PG_SYSLOG_LIMIT || nlpos != NULL))
1952 {
1953 int chunk_nr = 0;
1954
1955 while (len > 0)
1956 {
1957 char buf[PG_SYSLOG_LIMIT + 1];
1958 int buflen;
1959 int i;
1960
1961 /* if we start at a newline, move ahead one char */
1962 if (line[0] == '\n')
1963 {
1964 line++;
1965 len--;
1966 /* we need to recompute the next newline's position, too */
1967 nlpos = strchr(line, '\n');
1968 continue;
1969 }
1970
1971 /* copy one line, or as much as will fit, to buf */
1972 if (nlpos != NULL)
1973 buflen = nlpos - line;
1974 else
1975 buflen = len;
1976 buflen = Min(buflen, PG_SYSLOG_LIMIT);
1977 memcpy(buf, line, buflen);
1978 buf[buflen] = '\0';
1979
1980 /* trim to multibyte letter boundary */
1981 buflen = pg_mbcliplen(buf, buflen, buflen);
1982 if (buflen <= 0)
1983 return;
1984 buf[buflen] = '\0';
1985
1986 /* already word boundary? */
1987 if (line[buflen] != '\0' &&
1988 !isspace((unsigned char) line[buflen]))
1989 {
1990 /* try to divide at word boundary */
1991 i = buflen - 1;
1992 while (i > 0 && !isspace((unsigned char) buf[i]))
1993 i--;
1994
1995 if (i > 0) /* else couldn't divide word boundary */
1996 {
1997 buflen = i;
1998 buf[i] = '\0';
1999 }
2000 }
2001
2002 chunk_nr++;
2003
2004 if (syslog_sequence_numbers)
2005 syslog(level, "[%lu-%d] %s", seq, chunk_nr, buf);
2006 else
2007 syslog(level, "[%d] %s", chunk_nr, buf);
2008
2009 line += buflen;
2010 len -= buflen;
2011 }
2012 }
2013 else
2014 {
2015 /* message short enough */
2016 if (syslog_sequence_numbers)
2017 syslog(level, "[%lu] %s", seq, line);
2018 else
2019 syslog(level, "%s", line);
2020 }
2021 }
2022 #endif /* HAVE_SYSLOG */
2023
2024 #ifdef WIN32
2025 /*
2026 * Get the PostgreSQL equivalent of the Windows ANSI code page. "ANSI" system
2027 * interfaces (e.g. CreateFileA()) expect string arguments in this encoding.
2028 * Every process in a given system will find the same value at all times.
2029 */
2030 static int
GetACPEncoding(void)2031 GetACPEncoding(void)
2032 {
2033 static int encoding = -2;
2034
2035 if (encoding == -2)
2036 encoding = pg_codepage_to_encoding(GetACP());
2037
2038 return encoding;
2039 }
2040
2041 /*
2042 * Write a message line to the windows event log
2043 */
2044 static void
write_eventlog(int level,const char * line,int len)2045 write_eventlog(int level, const char *line, int len)
2046 {
2047 WCHAR *utf16;
2048 int eventlevel = EVENTLOG_ERROR_TYPE;
2049 static HANDLE evtHandle = INVALID_HANDLE_VALUE;
2050
2051 if (evtHandle == INVALID_HANDLE_VALUE)
2052 {
2053 evtHandle = RegisterEventSource(NULL,
2054 event_source ? event_source : DEFAULT_EVENT_SOURCE);
2055 if (evtHandle == NULL)
2056 {
2057 evtHandle = INVALID_HANDLE_VALUE;
2058 return;
2059 }
2060 }
2061
2062 switch (level)
2063 {
2064 case DEBUG5:
2065 case DEBUG4:
2066 case DEBUG3:
2067 case DEBUG2:
2068 case DEBUG1:
2069 case LOG:
2070 case LOG_SERVER_ONLY:
2071 case INFO:
2072 case NOTICE:
2073 eventlevel = EVENTLOG_INFORMATION_TYPE;
2074 break;
2075 case WARNING:
2076 eventlevel = EVENTLOG_WARNING_TYPE;
2077 break;
2078 case ERROR:
2079 case FATAL:
2080 case PANIC:
2081 default:
2082 eventlevel = EVENTLOG_ERROR_TYPE;
2083 break;
2084 }
2085
2086 /*
2087 * If message character encoding matches the encoding expected by
2088 * ReportEventA(), call it to avoid the hazards of conversion. Otherwise,
2089 * try to convert the message to UTF16 and write it with ReportEventW().
2090 * Fall back on ReportEventA() if conversion failed.
2091 *
2092 * Since we palloc the structure required for conversion, also fall
2093 * through to writing unconverted if we have not yet set up
2094 * CurrentMemoryContext.
2095 *
2096 * Also verify that we are not on our way into error recursion trouble due
2097 * to error messages thrown deep inside pgwin32_message_to_UTF16().
2098 */
2099 if (!in_error_recursion_trouble() &&
2100 CurrentMemoryContext != NULL &&
2101 GetMessageEncoding() != GetACPEncoding())
2102 {
2103 utf16 = pgwin32_message_to_UTF16(line, len, NULL);
2104 if (utf16)
2105 {
2106 ReportEventW(evtHandle,
2107 eventlevel,
2108 0,
2109 0, /* All events are Id 0 */
2110 NULL,
2111 1,
2112 0,
2113 (LPCWSTR *) &utf16,
2114 NULL);
2115 /* XXX Try ReportEventA() when ReportEventW() fails? */
2116
2117 pfree(utf16);
2118 return;
2119 }
2120 }
2121 ReportEventA(evtHandle,
2122 eventlevel,
2123 0,
2124 0, /* All events are Id 0 */
2125 NULL,
2126 1,
2127 0,
2128 &line,
2129 NULL);
2130 }
2131 #endif /* WIN32 */
2132
2133 static void
write_console(const char * line,int len)2134 write_console(const char *line, int len)
2135 {
2136 int rc;
2137
2138 #ifdef WIN32
2139
2140 /*
2141 * Try to convert the message to UTF16 and write it with WriteConsoleW().
2142 * Fall back on write() if anything fails.
2143 *
2144 * In contrast to write_eventlog(), don't skip straight to write() based
2145 * on the applicable encodings. Unlike WriteConsoleW(), write() depends
2146 * on the suitability of the console output code page. Since we put
2147 * stderr into binary mode in SubPostmasterMain(), write() skips the
2148 * necessary translation anyway.
2149 *
2150 * WriteConsoleW() will fail if stderr is redirected, so just fall through
2151 * to writing unconverted to the logfile in this case.
2152 *
2153 * Since we palloc the structure required for conversion, also fall
2154 * through to writing unconverted if we have not yet set up
2155 * CurrentMemoryContext.
2156 */
2157 if (!in_error_recursion_trouble() &&
2158 !redirection_done &&
2159 CurrentMemoryContext != NULL)
2160 {
2161 WCHAR *utf16;
2162 int utf16len;
2163
2164 utf16 = pgwin32_message_to_UTF16(line, len, &utf16len);
2165 if (utf16 != NULL)
2166 {
2167 HANDLE stdHandle;
2168 DWORD written;
2169
2170 stdHandle = GetStdHandle(STD_ERROR_HANDLE);
2171 if (WriteConsoleW(stdHandle, utf16, utf16len, &written, NULL))
2172 {
2173 pfree(utf16);
2174 return;
2175 }
2176
2177 /*
2178 * In case WriteConsoleW() failed, fall back to writing the
2179 * message unconverted.
2180 */
2181 pfree(utf16);
2182 }
2183 }
2184 #else
2185
2186 /*
2187 * Conversion on non-win32 platforms is not implemented yet. It requires
2188 * non-throw version of pg_do_encoding_conversion(), that converts
2189 * unconvertable characters to '?' without errors.
2190 */
2191 #endif
2192
2193 /*
2194 * We ignore any error from write() here. We have no useful way to report
2195 * it ... certainly whining on stderr isn't likely to be productive.
2196 */
2197 rc = write(fileno(stderr), line, len);
2198 (void) rc;
2199 }
2200
2201 /*
2202 * setup formatted_log_time, for consistent times between CSV and regular logs
2203 */
2204 static void
setup_formatted_log_time(void)2205 setup_formatted_log_time(void)
2206 {
2207 pg_time_t stamp_time;
2208 char msbuf[13];
2209
2210 if (!saved_timeval_set)
2211 {
2212 gettimeofday(&saved_timeval, NULL);
2213 saved_timeval_set = true;
2214 }
2215
2216 stamp_time = (pg_time_t) saved_timeval.tv_sec;
2217
2218 /*
2219 * Note: we expect that guc.c will ensure that log_timezone is set up (at
2220 * least with a minimal GMT value) before Log_line_prefix can become
2221 * nonempty or CSV mode can be selected.
2222 */
2223 pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
2224 /* leave room for milliseconds... */
2225 "%Y-%m-%d %H:%M:%S %Z",
2226 pg_localtime(&stamp_time, log_timezone));
2227
2228 /* 'paste' milliseconds into place... */
2229 sprintf(msbuf, ".%03d", (int) (saved_timeval.tv_usec / 1000));
2230 memcpy(formatted_log_time + 19, msbuf, 4);
2231 }
2232
2233 /*
2234 * setup formatted_start_time
2235 */
2236 static void
setup_formatted_start_time(void)2237 setup_formatted_start_time(void)
2238 {
2239 pg_time_t stamp_time = (pg_time_t) MyStartTime;
2240
2241 /*
2242 * Note: we expect that guc.c will ensure that log_timezone is set up (at
2243 * least with a minimal GMT value) before Log_line_prefix can become
2244 * nonempty or CSV mode can be selected.
2245 */
2246 pg_strftime(formatted_start_time, FORMATTED_TS_LEN,
2247 "%Y-%m-%d %H:%M:%S %Z",
2248 pg_localtime(&stamp_time, log_timezone));
2249 }
2250
2251 /*
2252 * process_log_prefix_padding --- helper function for processing the format
2253 * string in log_line_prefix
2254 *
2255 * Note: This function returns NULL if it finds something which
2256 * it deems invalid in the format string.
2257 */
2258 static const char *
process_log_prefix_padding(const char * p,int * ppadding)2259 process_log_prefix_padding(const char *p, int *ppadding)
2260 {
2261 int paddingsign = 1;
2262 int padding = 0;
2263
2264 if (*p == '-')
2265 {
2266 p++;
2267
2268 if (*p == '\0') /* Did the buf end in %- ? */
2269 return NULL;
2270 paddingsign = -1;
2271 }
2272
2273 /* generate an int version of the numerical string */
2274 while (*p >= '0' && *p <= '9')
2275 padding = padding * 10 + (*p++ - '0');
2276
2277 /* format is invalid if it ends with the padding number */
2278 if (*p == '\0')
2279 return NULL;
2280
2281 padding *= paddingsign;
2282 *ppadding = padding;
2283 return p;
2284 }
2285
2286 /*
2287 * Format tag info for log lines; append to the provided buffer.
2288 */
2289 static void
log_line_prefix(StringInfo buf,ErrorData * edata)2290 log_line_prefix(StringInfo buf, ErrorData *edata)
2291 {
2292 /* static counter for line numbers */
2293 static long log_line_number = 0;
2294
2295 /* has counter been reset in current process? */
2296 static int log_my_pid = 0;
2297 int padding;
2298 const char *p;
2299
2300 /*
2301 * This is one of the few places where we'd rather not inherit a static
2302 * variable's value from the postmaster. But since we will, reset it when
2303 * MyProcPid changes. MyStartTime also changes when MyProcPid does, so
2304 * reset the formatted start timestamp too.
2305 */
2306 if (log_my_pid != MyProcPid)
2307 {
2308 log_line_number = 0;
2309 log_my_pid = MyProcPid;
2310 formatted_start_time[0] = '\0';
2311 }
2312 log_line_number++;
2313
2314 if (Log_line_prefix == NULL)
2315 return; /* in case guc hasn't run yet */
2316
2317 for (p = Log_line_prefix; *p != '\0'; p++)
2318 {
2319 if (*p != '%')
2320 {
2321 /* literal char, just copy */
2322 appendStringInfoChar(buf, *p);
2323 continue;
2324 }
2325
2326 /* must be a '%', so skip to the next char */
2327 p++;
2328 if (*p == '\0')
2329 break; /* format error - ignore it */
2330 else if (*p == '%')
2331 {
2332 /* string contains %% */
2333 appendStringInfoChar(buf, '%');
2334 continue;
2335 }
2336
2337
2338 /*
2339 * Process any formatting which may exist after the '%'. Note that
2340 * process_log_prefix_padding moves p past the padding number if it
2341 * exists.
2342 *
2343 * Note: Since only '-', '0' to '9' are valid formatting characters we
2344 * can do a quick check here to pre-check for formatting. If the char
2345 * is not formatting then we can skip a useless function call.
2346 *
2347 * Further note: At least on some platforms, passing %*s rather than
2348 * %s to appendStringInfo() is substantially slower, so many of the
2349 * cases below avoid doing that unless non-zero padding is in fact
2350 * specified.
2351 */
2352 if (*p > '9')
2353 padding = 0;
2354 else if ((p = process_log_prefix_padding(p, &padding)) == NULL)
2355 break;
2356
2357 /* process the option */
2358 switch (*p)
2359 {
2360 case 'a':
2361 if (MyProcPort)
2362 {
2363 const char *appname = application_name;
2364
2365 if (appname == NULL || *appname == '\0')
2366 appname = _("[unknown]");
2367 if (padding != 0)
2368 appendStringInfo(buf, "%*s", padding, appname);
2369 else
2370 appendStringInfoString(buf, appname);
2371 }
2372 else if (padding != 0)
2373 appendStringInfoSpaces(buf,
2374 padding > 0 ? padding : -padding);
2375
2376 break;
2377 case 'u':
2378 if (MyProcPort)
2379 {
2380 const char *username = MyProcPort->user_name;
2381
2382 if (username == NULL || *username == '\0')
2383 username = _("[unknown]");
2384 if (padding != 0)
2385 appendStringInfo(buf, "%*s", padding, username);
2386 else
2387 appendStringInfoString(buf, username);
2388 }
2389 else if (padding != 0)
2390 appendStringInfoSpaces(buf,
2391 padding > 0 ? padding : -padding);
2392 break;
2393 case 'd':
2394 if (MyProcPort)
2395 {
2396 const char *dbname = MyProcPort->database_name;
2397
2398 if (dbname == NULL || *dbname == '\0')
2399 dbname = _("[unknown]");
2400 if (padding != 0)
2401 appendStringInfo(buf, "%*s", padding, dbname);
2402 else
2403 appendStringInfoString(buf, dbname);
2404 }
2405 else if (padding != 0)
2406 appendStringInfoSpaces(buf,
2407 padding > 0 ? padding : -padding);
2408 break;
2409 case 'c':
2410 if (padding != 0)
2411 {
2412 char strfbuf[128];
2413
2414 snprintf(strfbuf, sizeof(strfbuf) - 1, "%lx.%x",
2415 (long) (MyStartTime), MyProcPid);
2416 appendStringInfo(buf, "%*s", padding, strfbuf);
2417 }
2418 else
2419 appendStringInfo(buf, "%lx.%x", (long) (MyStartTime), MyProcPid);
2420 break;
2421 case 'p':
2422 if (padding != 0)
2423 appendStringInfo(buf, "%*d", padding, MyProcPid);
2424 else
2425 appendStringInfo(buf, "%d", MyProcPid);
2426 break;
2427 case 'l':
2428 if (padding != 0)
2429 appendStringInfo(buf, "%*ld", padding, log_line_number);
2430 else
2431 appendStringInfo(buf, "%ld", log_line_number);
2432 break;
2433 case 'm':
2434 setup_formatted_log_time();
2435 if (padding != 0)
2436 appendStringInfo(buf, "%*s", padding, formatted_log_time);
2437 else
2438 appendStringInfoString(buf, formatted_log_time);
2439 break;
2440 case 't':
2441 {
2442 pg_time_t stamp_time = (pg_time_t) time(NULL);
2443 char strfbuf[128];
2444
2445 pg_strftime(strfbuf, sizeof(strfbuf),
2446 "%Y-%m-%d %H:%M:%S %Z",
2447 pg_localtime(&stamp_time, log_timezone));
2448 if (padding != 0)
2449 appendStringInfo(buf, "%*s", padding, strfbuf);
2450 else
2451 appendStringInfoString(buf, strfbuf);
2452 }
2453 break;
2454 case 'n':
2455 {
2456 char strfbuf[128];
2457
2458 if (!saved_timeval_set)
2459 {
2460 gettimeofday(&saved_timeval, NULL);
2461 saved_timeval_set = true;
2462 }
2463
2464 snprintf(strfbuf, sizeof(strfbuf), "%ld.%03d",
2465 (long) saved_timeval.tv_sec,
2466 (int) (saved_timeval.tv_usec / 1000));
2467
2468 if (padding != 0)
2469 appendStringInfo(buf, "%*s", padding, strfbuf);
2470 else
2471 appendStringInfoString(buf, strfbuf);
2472 }
2473 break;
2474 case 's':
2475 if (formatted_start_time[0] == '\0')
2476 setup_formatted_start_time();
2477 if (padding != 0)
2478 appendStringInfo(buf, "%*s", padding, formatted_start_time);
2479 else
2480 appendStringInfoString(buf, formatted_start_time);
2481 break;
2482 case 'i':
2483 if (MyProcPort)
2484 {
2485 const char *psdisp;
2486 int displen;
2487
2488 psdisp = get_ps_display(&displen);
2489 if (padding != 0)
2490 appendStringInfo(buf, "%*s", padding, psdisp);
2491 else
2492 appendBinaryStringInfo(buf, psdisp, displen);
2493
2494 }
2495 else if (padding != 0)
2496 appendStringInfoSpaces(buf,
2497 padding > 0 ? padding : -padding);
2498 break;
2499 case 'r':
2500 if (MyProcPort && MyProcPort->remote_host)
2501 {
2502 if (padding != 0)
2503 {
2504 if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
2505 {
2506 /*
2507 * This option is slightly special as the port
2508 * number may be appended onto the end. Here we
2509 * need to build 1 string which contains the
2510 * remote_host and optionally the remote_port (if
2511 * set) so we can properly align the string.
2512 */
2513
2514 char *hostport;
2515
2516 hostport = psprintf("%s(%s)", MyProcPort->remote_host, MyProcPort->remote_port);
2517 appendStringInfo(buf, "%*s", padding, hostport);
2518 pfree(hostport);
2519 }
2520 else
2521 appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host);
2522 }
2523 else
2524 {
2525 /* padding is 0, so we don't need a temp buffer */
2526 appendStringInfoString(buf, MyProcPort->remote_host);
2527 if (MyProcPort->remote_port &&
2528 MyProcPort->remote_port[0] != '\0')
2529 appendStringInfo(buf, "(%s)",
2530 MyProcPort->remote_port);
2531 }
2532
2533 }
2534 else if (padding != 0)
2535 appendStringInfoSpaces(buf,
2536 padding > 0 ? padding : -padding);
2537 break;
2538 case 'h':
2539 if (MyProcPort && MyProcPort->remote_host)
2540 {
2541 if (padding != 0)
2542 appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host);
2543 else
2544 appendStringInfoString(buf, MyProcPort->remote_host);
2545 }
2546 else if (padding != 0)
2547 appendStringInfoSpaces(buf,
2548 padding > 0 ? padding : -padding);
2549 break;
2550 case 'q':
2551 /* in postmaster and friends, stop if %q is seen */
2552 /* in a backend, just ignore */
2553 if (MyProcPort == NULL)
2554 return;
2555 break;
2556 case 'v':
2557 /* keep VXID format in sync with lockfuncs.c */
2558 if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
2559 {
2560 if (padding != 0)
2561 {
2562 char strfbuf[128];
2563
2564 snprintf(strfbuf, sizeof(strfbuf) - 1, "%d/%u",
2565 MyProc->backendId, MyProc->lxid);
2566 appendStringInfo(buf, "%*s", padding, strfbuf);
2567 }
2568 else
2569 appendStringInfo(buf, "%d/%u", MyProc->backendId, MyProc->lxid);
2570 }
2571 else if (padding != 0)
2572 appendStringInfoSpaces(buf,
2573 padding > 0 ? padding : -padding);
2574 break;
2575 case 'x':
2576 if (padding != 0)
2577 appendStringInfo(buf, "%*u", padding, GetTopTransactionIdIfAny());
2578 else
2579 appendStringInfo(buf, "%u", GetTopTransactionIdIfAny());
2580 break;
2581 case 'e':
2582 if (padding != 0)
2583 appendStringInfo(buf, "%*s", padding, unpack_sql_state(edata->sqlerrcode));
2584 else
2585 appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode));
2586 break;
2587 default:
2588 /* format error - ignore it */
2589 break;
2590 }
2591 }
2592 }
2593
2594 /*
2595 * append a CSV'd version of a string to a StringInfo
2596 * We use the PostgreSQL defaults for CSV, i.e. quote = escape = '"'
2597 * If it's NULL, append nothing.
2598 */
2599 static inline void
appendCSVLiteral(StringInfo buf,const char * data)2600 appendCSVLiteral(StringInfo buf, const char *data)
2601 {
2602 const char *p = data;
2603 char c;
2604
2605 /* avoid confusing an empty string with NULL */
2606 if (p == NULL)
2607 return;
2608
2609 appendStringInfoCharMacro(buf, '"');
2610 while ((c = *p++) != '\0')
2611 {
2612 if (c == '"')
2613 appendStringInfoCharMacro(buf, '"');
2614 appendStringInfoCharMacro(buf, c);
2615 }
2616 appendStringInfoCharMacro(buf, '"');
2617 }
2618
2619 /*
2620 * Constructs the error message, depending on the Errordata it gets, in a CSV
2621 * format which is described in doc/src/sgml/config.sgml.
2622 */
2623 static void
write_csvlog(ErrorData * edata)2624 write_csvlog(ErrorData *edata)
2625 {
2626 StringInfoData buf;
2627 bool print_stmt = false;
2628
2629 /* static counter for line numbers */
2630 static long log_line_number = 0;
2631
2632 /* has counter been reset in current process? */
2633 static int log_my_pid = 0;
2634
2635 /*
2636 * This is one of the few places where we'd rather not inherit a static
2637 * variable's value from the postmaster. But since we will, reset it when
2638 * MyProcPid changes.
2639 */
2640 if (log_my_pid != MyProcPid)
2641 {
2642 log_line_number = 0;
2643 log_my_pid = MyProcPid;
2644 formatted_start_time[0] = '\0';
2645 }
2646 log_line_number++;
2647
2648 initStringInfo(&buf);
2649
2650 /*
2651 * timestamp with milliseconds
2652 *
2653 * Check if the timestamp is already calculated for the syslog message,
2654 * and use it if so. Otherwise, get the current timestamp. This is done
2655 * to put same timestamp in both syslog and csvlog messages.
2656 */
2657 if (formatted_log_time[0] == '\0')
2658 setup_formatted_log_time();
2659
2660 appendStringInfoString(&buf, formatted_log_time);
2661 appendStringInfoChar(&buf, ',');
2662
2663 /* username */
2664 if (MyProcPort)
2665 appendCSVLiteral(&buf, MyProcPort->user_name);
2666 appendStringInfoChar(&buf, ',');
2667
2668 /* database name */
2669 if (MyProcPort)
2670 appendCSVLiteral(&buf, MyProcPort->database_name);
2671 appendStringInfoChar(&buf, ',');
2672
2673 /* Process id */
2674 if (MyProcPid != 0)
2675 appendStringInfo(&buf, "%d", MyProcPid);
2676 appendStringInfoChar(&buf, ',');
2677
2678 /* Remote host and port */
2679 if (MyProcPort && MyProcPort->remote_host)
2680 {
2681 appendStringInfoChar(&buf, '"');
2682 appendStringInfoString(&buf, MyProcPort->remote_host);
2683 if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
2684 {
2685 appendStringInfoChar(&buf, ':');
2686 appendStringInfoString(&buf, MyProcPort->remote_port);
2687 }
2688 appendStringInfoChar(&buf, '"');
2689 }
2690 appendStringInfoChar(&buf, ',');
2691
2692 /* session id */
2693 appendStringInfo(&buf, "%lx.%x", (long) MyStartTime, MyProcPid);
2694 appendStringInfoChar(&buf, ',');
2695
2696 /* Line number */
2697 appendStringInfo(&buf, "%ld", log_line_number);
2698 appendStringInfoChar(&buf, ',');
2699
2700 /* PS display */
2701 if (MyProcPort)
2702 {
2703 StringInfoData msgbuf;
2704 const char *psdisp;
2705 int displen;
2706
2707 initStringInfo(&msgbuf);
2708
2709 psdisp = get_ps_display(&displen);
2710 appendBinaryStringInfo(&msgbuf, psdisp, displen);
2711 appendCSVLiteral(&buf, msgbuf.data);
2712
2713 pfree(msgbuf.data);
2714 }
2715 appendStringInfoChar(&buf, ',');
2716
2717 /* session start timestamp */
2718 if (formatted_start_time[0] == '\0')
2719 setup_formatted_start_time();
2720 appendStringInfoString(&buf, formatted_start_time);
2721 appendStringInfoChar(&buf, ',');
2722
2723 /* Virtual transaction id */
2724 /* keep VXID format in sync with lockfuncs.c */
2725 if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
2726 appendStringInfo(&buf, "%d/%u", MyProc->backendId, MyProc->lxid);
2727 appendStringInfoChar(&buf, ',');
2728
2729 /* Transaction id */
2730 appendStringInfo(&buf, "%u", GetTopTransactionIdIfAny());
2731 appendStringInfoChar(&buf, ',');
2732
2733 /* Error severity */
2734 appendStringInfoString(&buf, _(error_severity(edata->elevel)));
2735 appendStringInfoChar(&buf, ',');
2736
2737 /* SQL state code */
2738 appendStringInfoString(&buf, unpack_sql_state(edata->sqlerrcode));
2739 appendStringInfoChar(&buf, ',');
2740
2741 /* errmessage */
2742 appendCSVLiteral(&buf, edata->message);
2743 appendStringInfoChar(&buf, ',');
2744
2745 /* errdetail or errdetail_log */
2746 if (edata->detail_log)
2747 appendCSVLiteral(&buf, edata->detail_log);
2748 else
2749 appendCSVLiteral(&buf, edata->detail);
2750 appendStringInfoChar(&buf, ',');
2751
2752 /* errhint */
2753 appendCSVLiteral(&buf, edata->hint);
2754 appendStringInfoChar(&buf, ',');
2755
2756 /* internal query */
2757 appendCSVLiteral(&buf, edata->internalquery);
2758 appendStringInfoChar(&buf, ',');
2759
2760 /* if printed internal query, print internal pos too */
2761 if (edata->internalpos > 0 && edata->internalquery != NULL)
2762 appendStringInfo(&buf, "%d", edata->internalpos);
2763 appendStringInfoChar(&buf, ',');
2764
2765 /* errcontext */
2766 if (!edata->hide_ctx)
2767 appendCSVLiteral(&buf, edata->context);
2768 appendStringInfoChar(&buf, ',');
2769
2770 /* user query --- only reported if not disabled by the caller */
2771 if (is_log_level_output(edata->elevel, log_min_error_statement) &&
2772 debug_query_string != NULL &&
2773 !edata->hide_stmt)
2774 print_stmt = true;
2775 if (print_stmt)
2776 appendCSVLiteral(&buf, debug_query_string);
2777 appendStringInfoChar(&buf, ',');
2778 if (print_stmt && edata->cursorpos > 0)
2779 appendStringInfo(&buf, "%d", edata->cursorpos);
2780 appendStringInfoChar(&buf, ',');
2781
2782 /* file error location */
2783 if (Log_error_verbosity >= PGERROR_VERBOSE)
2784 {
2785 StringInfoData msgbuf;
2786
2787 initStringInfo(&msgbuf);
2788
2789 if (edata->funcname && edata->filename)
2790 appendStringInfo(&msgbuf, "%s, %s:%d",
2791 edata->funcname, edata->filename,
2792 edata->lineno);
2793 else if (edata->filename)
2794 appendStringInfo(&msgbuf, "%s:%d",
2795 edata->filename, edata->lineno);
2796 appendCSVLiteral(&buf, msgbuf.data);
2797 pfree(msgbuf.data);
2798 }
2799 appendStringInfoChar(&buf, ',');
2800
2801 /* application name */
2802 if (application_name)
2803 appendCSVLiteral(&buf, application_name);
2804
2805 appendStringInfoChar(&buf, '\n');
2806
2807 /* If in the syslogger process, try to write messages direct to file */
2808 if (am_syslogger)
2809 write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
2810 else
2811 write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
2812
2813 pfree(buf.data);
2814 }
2815
2816 /*
2817 * Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a
2818 * static buffer.
2819 */
2820 char *
unpack_sql_state(int sql_state)2821 unpack_sql_state(int sql_state)
2822 {
2823 static char buf[12];
2824 int i;
2825
2826 for (i = 0; i < 5; i++)
2827 {
2828 buf[i] = PGUNSIXBIT(sql_state);
2829 sql_state >>= 6;
2830 }
2831
2832 buf[i] = '\0';
2833 return buf;
2834 }
2835
2836
2837 /*
2838 * Write error report to server's log
2839 */
2840 static void
send_message_to_server_log(ErrorData * edata)2841 send_message_to_server_log(ErrorData *edata)
2842 {
2843 StringInfoData buf;
2844
2845 initStringInfo(&buf);
2846
2847 saved_timeval_set = false;
2848 formatted_log_time[0] = '\0';
2849
2850 log_line_prefix(&buf, edata);
2851 appendStringInfo(&buf, "%s: ", _(error_severity(edata->elevel)));
2852
2853 if (Log_error_verbosity >= PGERROR_VERBOSE)
2854 appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode));
2855
2856 if (edata->message)
2857 append_with_tabs(&buf, edata->message);
2858 else
2859 append_with_tabs(&buf, _("missing error text"));
2860
2861 if (edata->cursorpos > 0)
2862 appendStringInfo(&buf, _(" at character %d"),
2863 edata->cursorpos);
2864 else if (edata->internalpos > 0)
2865 appendStringInfo(&buf, _(" at character %d"),
2866 edata->internalpos);
2867
2868 appendStringInfoChar(&buf, '\n');
2869
2870 if (Log_error_verbosity >= PGERROR_DEFAULT)
2871 {
2872 if (edata->detail_log)
2873 {
2874 log_line_prefix(&buf, edata);
2875 appendStringInfoString(&buf, _("DETAIL: "));
2876 append_with_tabs(&buf, edata->detail_log);
2877 appendStringInfoChar(&buf, '\n');
2878 }
2879 else if (edata->detail)
2880 {
2881 log_line_prefix(&buf, edata);
2882 appendStringInfoString(&buf, _("DETAIL: "));
2883 append_with_tabs(&buf, edata->detail);
2884 appendStringInfoChar(&buf, '\n');
2885 }
2886 if (edata->hint)
2887 {
2888 log_line_prefix(&buf, edata);
2889 appendStringInfoString(&buf, _("HINT: "));
2890 append_with_tabs(&buf, edata->hint);
2891 appendStringInfoChar(&buf, '\n');
2892 }
2893 if (edata->internalquery)
2894 {
2895 log_line_prefix(&buf, edata);
2896 appendStringInfoString(&buf, _("QUERY: "));
2897 append_with_tabs(&buf, edata->internalquery);
2898 appendStringInfoChar(&buf, '\n');
2899 }
2900 if (edata->context && !edata->hide_ctx)
2901 {
2902 log_line_prefix(&buf, edata);
2903 appendStringInfoString(&buf, _("CONTEXT: "));
2904 append_with_tabs(&buf, edata->context);
2905 appendStringInfoChar(&buf, '\n');
2906 }
2907 if (Log_error_verbosity >= PGERROR_VERBOSE)
2908 {
2909 /* assume no newlines in funcname or filename... */
2910 if (edata->funcname && edata->filename)
2911 {
2912 log_line_prefix(&buf, edata);
2913 appendStringInfo(&buf, _("LOCATION: %s, %s:%d\n"),
2914 edata->funcname, edata->filename,
2915 edata->lineno);
2916 }
2917 else if (edata->filename)
2918 {
2919 log_line_prefix(&buf, edata);
2920 appendStringInfo(&buf, _("LOCATION: %s:%d\n"),
2921 edata->filename, edata->lineno);
2922 }
2923 }
2924 }
2925
2926 /*
2927 * If the user wants the query that generated this error logged, do it.
2928 */
2929 if (is_log_level_output(edata->elevel, log_min_error_statement) &&
2930 debug_query_string != NULL &&
2931 !edata->hide_stmt)
2932 {
2933 log_line_prefix(&buf, edata);
2934 appendStringInfoString(&buf, _("STATEMENT: "));
2935 append_with_tabs(&buf, debug_query_string);
2936 appendStringInfoChar(&buf, '\n');
2937 }
2938
2939 #ifdef HAVE_SYSLOG
2940 /* Write to syslog, if enabled */
2941 if (Log_destination & LOG_DESTINATION_SYSLOG)
2942 {
2943 int syslog_level;
2944
2945 switch (edata->elevel)
2946 {
2947 case DEBUG5:
2948 case DEBUG4:
2949 case DEBUG3:
2950 case DEBUG2:
2951 case DEBUG1:
2952 syslog_level = LOG_DEBUG;
2953 break;
2954 case LOG:
2955 case LOG_SERVER_ONLY:
2956 case INFO:
2957 syslog_level = LOG_INFO;
2958 break;
2959 case NOTICE:
2960 case WARNING:
2961 syslog_level = LOG_NOTICE;
2962 break;
2963 case ERROR:
2964 syslog_level = LOG_WARNING;
2965 break;
2966 case FATAL:
2967 syslog_level = LOG_ERR;
2968 break;
2969 case PANIC:
2970 default:
2971 syslog_level = LOG_CRIT;
2972 break;
2973 }
2974
2975 write_syslog(syslog_level, buf.data);
2976 }
2977 #endif /* HAVE_SYSLOG */
2978
2979 #ifdef WIN32
2980 /* Write to eventlog, if enabled */
2981 if (Log_destination & LOG_DESTINATION_EVENTLOG)
2982 {
2983 write_eventlog(edata->elevel, buf.data, buf.len);
2984 }
2985 #endif /* WIN32 */
2986
2987 /* Write to stderr, if enabled */
2988 if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug)
2989 {
2990 /*
2991 * Use the chunking protocol if we know the syslogger should be
2992 * catching stderr output, and we are not ourselves the syslogger.
2993 * Otherwise, just do a vanilla write to stderr.
2994 */
2995 if (redirection_done && !am_syslogger)
2996 write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_STDERR);
2997 #ifdef WIN32
2998
2999 /*
3000 * In a win32 service environment, there is no usable stderr. Capture
3001 * anything going there and write it to the eventlog instead.
3002 *
3003 * If stderr redirection is active, it was OK to write to stderr above
3004 * because that's really a pipe to the syslogger process.
3005 */
3006 else if (pgwin32_is_service())
3007 write_eventlog(edata->elevel, buf.data, buf.len);
3008 #endif
3009 else
3010 write_console(buf.data, buf.len);
3011 }
3012
3013 /* If in the syslogger process, try to write messages direct to file */
3014 if (am_syslogger)
3015 write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_STDERR);
3016
3017 /* Write to CSV log if enabled */
3018 if (Log_destination & LOG_DESTINATION_CSVLOG)
3019 {
3020 if (redirection_done || am_syslogger)
3021 {
3022 /*
3023 * send CSV data if it's safe to do so (syslogger doesn't need the
3024 * pipe). First get back the space in the message buffer.
3025 */
3026 pfree(buf.data);
3027 write_csvlog(edata);
3028 }
3029 else
3030 {
3031 /*
3032 * syslogger not up (yet), so just dump the message to stderr,
3033 * unless we already did so above.
3034 */
3035 if (!(Log_destination & LOG_DESTINATION_STDERR) &&
3036 whereToSendOutput != DestDebug)
3037 write_console(buf.data, buf.len);
3038 pfree(buf.data);
3039 }
3040 }
3041 else
3042 {
3043 pfree(buf.data);
3044 }
3045 }
3046
3047 /*
3048 * Send data to the syslogger using the chunked protocol
3049 *
3050 * Note: when there are multiple backends writing into the syslogger pipe,
3051 * it's critical that each write go into the pipe indivisibly, and not
3052 * get interleaved with data from other processes. Fortunately, the POSIX
3053 * spec requires that writes to pipes be atomic so long as they are not
3054 * more than PIPE_BUF bytes long. So we divide long messages into chunks
3055 * that are no more than that length, and send one chunk per write() call.
3056 * The collector process knows how to reassemble the chunks.
3057 *
3058 * Because of the atomic write requirement, there are only two possible
3059 * results from write() here: -1 for failure, or the requested number of
3060 * bytes. There is not really anything we can do about a failure; retry would
3061 * probably be an infinite loop, and we can't even report the error usefully.
3062 * (There is noplace else we could send it!) So we might as well just ignore
3063 * the result from write(). However, on some platforms you get a compiler
3064 * warning from ignoring write()'s result, so do a little dance with casting
3065 * rc to void to shut up the compiler.
3066 */
3067 static void
write_pipe_chunks(char * data,int len,int dest)3068 write_pipe_chunks(char *data, int len, int dest)
3069 {
3070 PipeProtoChunk p;
3071 int fd = fileno(stderr);
3072 int rc;
3073
3074 Assert(len > 0);
3075
3076 p.proto.nuls[0] = p.proto.nuls[1] = '\0';
3077 p.proto.pid = MyProcPid;
3078
3079 /* write all but the last chunk */
3080 while (len > PIPE_MAX_PAYLOAD)
3081 {
3082 p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'F' : 'f');
3083 p.proto.len = PIPE_MAX_PAYLOAD;
3084 memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD);
3085 rc = write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD);
3086 (void) rc;
3087 data += PIPE_MAX_PAYLOAD;
3088 len -= PIPE_MAX_PAYLOAD;
3089 }
3090
3091 /* write the last chunk */
3092 p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'T' : 't');
3093 p.proto.len = len;
3094 memcpy(p.proto.data, data, len);
3095 rc = write(fd, &p, PIPE_HEADER_SIZE + len);
3096 (void) rc;
3097 }
3098
3099
3100 /*
3101 * Append a text string to the error report being built for the client.
3102 *
3103 * This is ordinarily identical to pq_sendstring(), but if we are in
3104 * error recursion trouble we skip encoding conversion, because of the
3105 * possibility that the problem is a failure in the encoding conversion
3106 * subsystem itself. Code elsewhere should ensure that the passed-in
3107 * strings will be plain 7-bit ASCII, and thus not in need of conversion,
3108 * in such cases. (In particular, we disable localization of error messages
3109 * to help ensure that's true.)
3110 */
3111 static void
err_sendstring(StringInfo buf,const char * str)3112 err_sendstring(StringInfo buf, const char *str)
3113 {
3114 if (in_error_recursion_trouble())
3115 pq_send_ascii_string(buf, str);
3116 else
3117 pq_sendstring(buf, str);
3118 }
3119
3120 /*
3121 * Write error report to client
3122 */
3123 static void
send_message_to_frontend(ErrorData * edata)3124 send_message_to_frontend(ErrorData *edata)
3125 {
3126 StringInfoData msgbuf;
3127
3128 /* 'N' (Notice) is for nonfatal conditions, 'E' is for errors */
3129 pq_beginmessage(&msgbuf, (edata->elevel < ERROR) ? 'N' : 'E');
3130
3131 if (PG_PROTOCOL_MAJOR(FrontendProtocol) >= 3)
3132 {
3133 /* New style with separate fields */
3134 const char *sev;
3135 char tbuf[12];
3136 int ssval;
3137 int i;
3138
3139 sev = error_severity(edata->elevel);
3140 pq_sendbyte(&msgbuf, PG_DIAG_SEVERITY);
3141 err_sendstring(&msgbuf, _(sev));
3142 pq_sendbyte(&msgbuf, PG_DIAG_SEVERITY_NONLOCALIZED);
3143 err_sendstring(&msgbuf, sev);
3144
3145 /* unpack MAKE_SQLSTATE code */
3146 ssval = edata->sqlerrcode;
3147 for (i = 0; i < 5; i++)
3148 {
3149 tbuf[i] = PGUNSIXBIT(ssval);
3150 ssval >>= 6;
3151 }
3152 tbuf[i] = '\0';
3153
3154 pq_sendbyte(&msgbuf, PG_DIAG_SQLSTATE);
3155 err_sendstring(&msgbuf, tbuf);
3156
3157 /* M field is required per protocol, so always send something */
3158 pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_PRIMARY);
3159 if (edata->message)
3160 err_sendstring(&msgbuf, edata->message);
3161 else
3162 err_sendstring(&msgbuf, _("missing error text"));
3163
3164 if (edata->detail)
3165 {
3166 pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_DETAIL);
3167 err_sendstring(&msgbuf, edata->detail);
3168 }
3169
3170 /* detail_log is intentionally not used here */
3171
3172 if (edata->hint)
3173 {
3174 pq_sendbyte(&msgbuf, PG_DIAG_MESSAGE_HINT);
3175 err_sendstring(&msgbuf, edata->hint);
3176 }
3177
3178 if (edata->context)
3179 {
3180 pq_sendbyte(&msgbuf, PG_DIAG_CONTEXT);
3181 err_sendstring(&msgbuf, edata->context);
3182 }
3183
3184 if (edata->schema_name)
3185 {
3186 pq_sendbyte(&msgbuf, PG_DIAG_SCHEMA_NAME);
3187 err_sendstring(&msgbuf, edata->schema_name);
3188 }
3189
3190 if (edata->table_name)
3191 {
3192 pq_sendbyte(&msgbuf, PG_DIAG_TABLE_NAME);
3193 err_sendstring(&msgbuf, edata->table_name);
3194 }
3195
3196 if (edata->column_name)
3197 {
3198 pq_sendbyte(&msgbuf, PG_DIAG_COLUMN_NAME);
3199 err_sendstring(&msgbuf, edata->column_name);
3200 }
3201
3202 if (edata->datatype_name)
3203 {
3204 pq_sendbyte(&msgbuf, PG_DIAG_DATATYPE_NAME);
3205 err_sendstring(&msgbuf, edata->datatype_name);
3206 }
3207
3208 if (edata->constraint_name)
3209 {
3210 pq_sendbyte(&msgbuf, PG_DIAG_CONSTRAINT_NAME);
3211 err_sendstring(&msgbuf, edata->constraint_name);
3212 }
3213
3214 if (edata->cursorpos > 0)
3215 {
3216 snprintf(tbuf, sizeof(tbuf), "%d", edata->cursorpos);
3217 pq_sendbyte(&msgbuf, PG_DIAG_STATEMENT_POSITION);
3218 err_sendstring(&msgbuf, tbuf);
3219 }
3220
3221 if (edata->internalpos > 0)
3222 {
3223 snprintf(tbuf, sizeof(tbuf), "%d", edata->internalpos);
3224 pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_POSITION);
3225 err_sendstring(&msgbuf, tbuf);
3226 }
3227
3228 if (edata->internalquery)
3229 {
3230 pq_sendbyte(&msgbuf, PG_DIAG_INTERNAL_QUERY);
3231 err_sendstring(&msgbuf, edata->internalquery);
3232 }
3233
3234 if (edata->filename)
3235 {
3236 pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FILE);
3237 err_sendstring(&msgbuf, edata->filename);
3238 }
3239
3240 if (edata->lineno > 0)
3241 {
3242 snprintf(tbuf, sizeof(tbuf), "%d", edata->lineno);
3243 pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_LINE);
3244 err_sendstring(&msgbuf, tbuf);
3245 }
3246
3247 if (edata->funcname)
3248 {
3249 pq_sendbyte(&msgbuf, PG_DIAG_SOURCE_FUNCTION);
3250 err_sendstring(&msgbuf, edata->funcname);
3251 }
3252
3253 pq_sendbyte(&msgbuf, '\0'); /* terminator */
3254 }
3255 else
3256 {
3257 /* Old style --- gin up a backwards-compatible message */
3258 StringInfoData buf;
3259
3260 initStringInfo(&buf);
3261
3262 appendStringInfo(&buf, "%s: ", _(error_severity(edata->elevel)));
3263
3264 if (edata->show_funcname && edata->funcname)
3265 appendStringInfo(&buf, "%s: ", edata->funcname);
3266
3267 if (edata->message)
3268 appendStringInfoString(&buf, edata->message);
3269 else
3270 appendStringInfoString(&buf, _("missing error text"));
3271
3272 if (edata->cursorpos > 0)
3273 appendStringInfo(&buf, _(" at character %d"),
3274 edata->cursorpos);
3275 else if (edata->internalpos > 0)
3276 appendStringInfo(&buf, _(" at character %d"),
3277 edata->internalpos);
3278
3279 appendStringInfoChar(&buf, '\n');
3280
3281 err_sendstring(&msgbuf, buf.data);
3282
3283 pfree(buf.data);
3284 }
3285
3286 pq_endmessage(&msgbuf);
3287
3288 /*
3289 * This flush is normally not necessary, since postgres.c will flush out
3290 * waiting data when control returns to the main loop. But it seems best
3291 * to leave it here, so that the client has some clue what happened if the
3292 * backend dies before getting back to the main loop ... error/notice
3293 * messages should not be a performance-critical path anyway, so an extra
3294 * flush won't hurt much ...
3295 */
3296 pq_flush();
3297 }
3298
3299
3300 /*
3301 * Support routines for formatting error messages.
3302 */
3303
3304
3305 /*
3306 * error_severity --- get string representing elevel
3307 *
3308 * The string is not localized here, but we mark the strings for translation
3309 * so that callers can invoke _() on the result.
3310 */
3311 static const char *
error_severity(int elevel)3312 error_severity(int elevel)
3313 {
3314 const char *prefix;
3315
3316 switch (elevel)
3317 {
3318 case DEBUG1:
3319 case DEBUG2:
3320 case DEBUG3:
3321 case DEBUG4:
3322 case DEBUG5:
3323 prefix = gettext_noop("DEBUG");
3324 break;
3325 case LOG:
3326 case LOG_SERVER_ONLY:
3327 prefix = gettext_noop("LOG");
3328 break;
3329 case INFO:
3330 prefix = gettext_noop("INFO");
3331 break;
3332 case NOTICE:
3333 prefix = gettext_noop("NOTICE");
3334 break;
3335 case WARNING:
3336 prefix = gettext_noop("WARNING");
3337 break;
3338 case ERROR:
3339 prefix = gettext_noop("ERROR");
3340 break;
3341 case FATAL:
3342 prefix = gettext_noop("FATAL");
3343 break;
3344 case PANIC:
3345 prefix = gettext_noop("PANIC");
3346 break;
3347 default:
3348 prefix = "???";
3349 break;
3350 }
3351
3352 return prefix;
3353 }
3354
3355
3356 /*
3357 * append_with_tabs
3358 *
3359 * Append the string to the StringInfo buffer, inserting a tab after any
3360 * newline.
3361 */
3362 static void
append_with_tabs(StringInfo buf,const char * str)3363 append_with_tabs(StringInfo buf, const char *str)
3364 {
3365 char ch;
3366
3367 while ((ch = *str++) != '\0')
3368 {
3369 appendStringInfoCharMacro(buf, ch);
3370 if (ch == '\n')
3371 appendStringInfoCharMacro(buf, '\t');
3372 }
3373 }
3374
3375
3376 /*
3377 * Write errors to stderr (or by equal means when stderr is
3378 * not available). Used before ereport/elog can be used
3379 * safely (memory context, GUC load etc)
3380 */
3381 void
write_stderr(const char * fmt,...)3382 write_stderr(const char *fmt,...)
3383 {
3384 va_list ap;
3385
3386 #ifdef WIN32
3387 char errbuf[2048]; /* Arbitrary size? */
3388 #endif
3389
3390 fmt = _(fmt);
3391
3392 va_start(ap, fmt);
3393 #ifndef WIN32
3394 /* On Unix, we just fprintf to stderr */
3395 vfprintf(stderr, fmt, ap);
3396 fflush(stderr);
3397 #else
3398 vsnprintf(errbuf, sizeof(errbuf), fmt, ap);
3399
3400 /*
3401 * On Win32, we print to stderr if running on a console, or write to
3402 * eventlog if running as a service
3403 */
3404 if (pgwin32_is_service()) /* Running as a service */
3405 {
3406 write_eventlog(ERROR, errbuf, strlen(errbuf));
3407 }
3408 else
3409 {
3410 /* Not running as service, write to stderr */
3411 write_console(errbuf, strlen(errbuf));
3412 fflush(stderr);
3413 }
3414 #endif
3415 va_end(ap);
3416 }
3417
3418
3419 /*
3420 * is_log_level_output -- is elevel logically >= log_min_level?
3421 *
3422 * We use this for tests that should consider LOG to sort out-of-order,
3423 * between ERROR and FATAL. Generally this is the right thing for testing
3424 * whether a message should go to the postmaster log, whereas a simple >=
3425 * test is correct for testing whether the message should go to the client.
3426 */
3427 static bool
is_log_level_output(int elevel,int log_min_level)3428 is_log_level_output(int elevel, int log_min_level)
3429 {
3430 if (elevel == LOG || elevel == LOG_SERVER_ONLY)
3431 {
3432 if (log_min_level == LOG || log_min_level <= ERROR)
3433 return true;
3434 }
3435 else if (log_min_level == LOG)
3436 {
3437 /* elevel != LOG */
3438 if (elevel >= FATAL)
3439 return true;
3440 }
3441 /* Neither is LOG */
3442 else if (elevel >= log_min_level)
3443 return true;
3444
3445 return false;
3446 }
3447
3448 /*
3449 * Adjust the level of a recovery-related message per trace_recovery_messages.
3450 *
3451 * The argument is the default log level of the message, eg, DEBUG2. (This
3452 * should only be applied to DEBUGn log messages, otherwise it's a no-op.)
3453 * If the level is >= trace_recovery_messages, we return LOG, causing the
3454 * message to be logged unconditionally (for most settings of
3455 * log_min_messages). Otherwise, we return the argument unchanged.
3456 * The message will then be shown based on the setting of log_min_messages.
3457 *
3458 * Intention is to keep this for at least the whole of the 9.0 production
3459 * release, so we can more easily diagnose production problems in the field.
3460 * It should go away eventually, though, because it's an ugly and
3461 * hard-to-explain kluge.
3462 */
3463 int
trace_recovery(int trace_level)3464 trace_recovery(int trace_level)
3465 {
3466 if (trace_level < LOG &&
3467 trace_level >= trace_recovery_messages)
3468 return LOG;
3469
3470 return trace_level;
3471 }
3472