Query in SQL function still not schema-safe; add a couple
[PostgreSQL.git] / src / backend / postmaster / syslogger.c
blobdfec8a90faaf3e4fe452ff3cefae079a3de5c8c0
1 /*-------------------------------------------------------------------------
3 * syslogger.c
5 * The system logger (syslogger) is new in Postgres 8.0. It catches all
6 * stderr output from the postmaster, backends, and other subprocesses
7 * by redirecting to a pipe, and writes it to a set of logfiles.
8 * It's possible to have size and age limits for the logfile configured
9 * in postgresql.conf. If these limits are reached or passed, the
10 * current logfile is closed and a new one is created (rotated).
11 * The logfiles are stored in a subdirectory (configurable in
12 * postgresql.conf), using an internal naming scheme that mangles
13 * creation time and current postmaster pid.
15 * Author: Andreas Pflug <pgadmin@pse-consulting.de>
17 * Copyright (c) 2004-2009, PostgreSQL Global Development Group
20 * IDENTIFICATION
21 * $PostgreSQL$
23 *-------------------------------------------------------------------------
25 #include "postgres.h"
27 #include <fcntl.h>
28 #include <signal.h>
29 #include <time.h>
30 #include <unistd.h>
31 #include <sys/stat.h>
32 #include <sys/time.h>
34 #include "lib/stringinfo.h"
35 #include "libpq/pqsignal.h"
36 #include "miscadmin.h"
37 #include "pgtime.h"
38 #include "postmaster/fork_process.h"
39 #include "postmaster/postmaster.h"
40 #include "postmaster/syslogger.h"
41 #include "storage/ipc.h"
42 #include "storage/pg_shmem.h"
43 #include "utils/guc.h"
44 #include "utils/ps_status.h"
45 #include "utils/timestamp.h"
48 * We really want line-buffered mode for logfile output, but Windows does
49 * not have it, and interprets _IOLBF as _IOFBF (bozos). So use _IONBF
50 * instead on Windows.
52 #ifdef WIN32
53 #define LBF_MODE _IONBF
54 #else
55 #define LBF_MODE _IOLBF
56 #endif
59 * We read() into a temp buffer twice as big as a chunk, so that any fragment
60 * left after processing can be moved down to the front and we'll still have
61 * room to read a full chunk.
63 #define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)
67 * GUC parameters. Logging_collector cannot be changed after postmaster
68 * start, but the rest can change at SIGHUP.
70 bool Logging_collector = false;
71 int Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
72 int Log_RotationSize = 10 * 1024;
73 char *Log_directory = NULL;
74 char *Log_filename = NULL;
75 bool Log_truncate_on_rotation = false;
78 * Globally visible state (used by elog.c)
80 bool am_syslogger = false;
82 extern bool redirection_done;
85 * Private state
87 static pg_time_t next_rotation_time;
88 static bool pipe_eof_seen = false;
89 static FILE *syslogFile = NULL;
90 static FILE *csvlogFile = NULL;
91 static char *last_file_name = NULL;
92 static char *last_csv_file_name = NULL;
95 * Buffers for saving partial messages from different backends. We don't expect
96 * that there will be very many outstanding at one time, so 20 seems plenty of
97 * leeway. If this array gets full we won't lose messages, but we will lose
98 * the protocol protection against them being partially written or interleaved.
100 * An inactive buffer has pid == 0 and undefined contents of data.
102 typedef struct
104 int32 pid; /* PID of source process */
105 StringInfoData data; /* accumulated data, as a StringInfo */
106 } save_buffer;
108 #define CHUNK_SLOTS 20
109 static save_buffer saved_chunks[CHUNK_SLOTS];
111 /* These must be exported for EXEC_BACKEND case ... annoying */
112 #ifndef WIN32
113 int syslogPipe[2] = {-1, -1};
114 #else
115 HANDLE syslogPipe[2] = {0, 0};
116 #endif
118 #ifdef WIN32
119 static HANDLE threadHandle = 0;
120 static CRITICAL_SECTION sysfileSection;
121 #endif
124 * Flags set by interrupt handlers for later service in the main loop.
126 static volatile sig_atomic_t got_SIGHUP = false;
127 static volatile sig_atomic_t rotation_requested = false;
130 /* Local subroutines */
131 #ifdef EXEC_BACKEND
132 static pid_t syslogger_forkexec(void);
133 static void syslogger_parseArgs(int argc, char *argv[]);
134 #endif
135 static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
136 static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
137 static void open_csvlogfile(void);
139 #ifdef WIN32
140 static unsigned int __stdcall pipeThread(void *arg);
141 #endif
142 static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
143 static char *logfile_getname(pg_time_t timestamp, char *suffix);
144 static void set_next_rotation_time(void);
145 static void sigHupHandler(SIGNAL_ARGS);
146 static void sigUsr1Handler(SIGNAL_ARGS);
150 * Main entry point for syslogger process
151 * argc/argv parameters are valid only in EXEC_BACKEND case.
153 NON_EXEC_STATIC void
154 SysLoggerMain(int argc, char *argv[])
156 #ifndef WIN32
157 char logbuffer[READ_BUF_SIZE];
158 int bytes_in_logbuffer = 0;
159 #endif
160 char *currentLogDir;
161 char *currentLogFilename;
162 int currentLogRotationAge;
164 IsUnderPostmaster = true; /* we are a postmaster subprocess now */
166 MyProcPid = getpid(); /* reset MyProcPid */
168 MyStartTime = time(NULL); /* set our start time in case we call elog */
170 #ifdef EXEC_BACKEND
171 syslogger_parseArgs(argc, argv);
172 #endif /* EXEC_BACKEND */
174 am_syslogger = true;
176 init_ps_display("logger process", "", "", "");
179 * If we restarted, our stderr is already redirected into our own input
180 * pipe. This is of course pretty useless, not to mention that it
181 * interferes with detecting pipe EOF. Point stderr to /dev/null. This
182 * assumes that all interesting messages generated in the syslogger will
183 * come through elog.c and will be sent to write_syslogger_file.
185 if (redirection_done)
187 int fd = open(DEVNULL, O_WRONLY, 0);
190 * The closes might look redundant, but they are not: we want to be
191 * darn sure the pipe gets closed even if the open failed. We can
192 * survive running with stderr pointing nowhere, but we can't afford
193 * to have extra pipe input descriptors hanging around.
195 close(fileno(stdout));
196 close(fileno(stderr));
197 dup2(fd, fileno(stdout));
198 dup2(fd, fileno(stderr));
199 close(fd);
203 * Syslogger's own stderr can't be the syslogPipe, so set it back to text
204 * mode if we didn't just close it. (It was set to binary in
205 * SubPostmasterMain).
207 #ifdef WIN32
208 else
209 _setmode(_fileno(stderr), _O_TEXT);
210 #endif
213 * Also close our copy of the write end of the pipe. This is needed to
214 * ensure we can detect pipe EOF correctly. (But note that in the restart
215 * case, the postmaster already did this.)
217 #ifndef WIN32
218 if (syslogPipe[1] >= 0)
219 close(syslogPipe[1]);
220 syslogPipe[1] = -1;
221 #else
222 if (syslogPipe[1])
223 CloseHandle(syslogPipe[1]);
224 syslogPipe[1] = 0;
225 #endif
228 * If possible, make this process a group leader, so that the postmaster
229 * can signal any child processes too. (syslogger probably never has any
230 * child processes, but for consistency we make all postmaster child
231 * processes do this.)
233 #ifdef HAVE_SETSID
234 if (setsid() < 0)
235 elog(FATAL, "setsid() failed: %m");
236 #endif
239 * Properly accept or ignore signals the postmaster might send us
241 * Note: we ignore all termination signals, and instead exit only when all
242 * upstream processes are gone, to ensure we don't miss any dying gasps of
243 * broken backends...
246 pqsignal(SIGHUP, sigHupHandler); /* set flag to read config file */
247 pqsignal(SIGINT, SIG_IGN);
248 pqsignal(SIGTERM, SIG_IGN);
249 pqsignal(SIGQUIT, SIG_IGN);
250 pqsignal(SIGALRM, SIG_IGN);
251 pqsignal(SIGPIPE, SIG_IGN);
252 pqsignal(SIGUSR1, sigUsr1Handler); /* request log rotation */
253 pqsignal(SIGUSR2, SIG_IGN);
256 * Reset some signals that are accepted by postmaster but not here
258 pqsignal(SIGCHLD, SIG_DFL);
259 pqsignal(SIGTTIN, SIG_DFL);
260 pqsignal(SIGTTOU, SIG_DFL);
261 pqsignal(SIGCONT, SIG_DFL);
262 pqsignal(SIGWINCH, SIG_DFL);
264 PG_SETMASK(&UnBlockSig);
266 #ifdef WIN32
267 /* Fire up separate data transfer thread */
268 InitializeCriticalSection(&sysfileSection);
270 threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
271 if (threadHandle == 0)
272 elog(FATAL, "could not create syslogger data transfer thread: %m");
273 #endif /* WIN32 */
275 /* remember active logfile parameters */
276 currentLogDir = pstrdup(Log_directory);
277 currentLogFilename = pstrdup(Log_filename);
278 currentLogRotationAge = Log_RotationAge;
279 /* set next planned rotation time */
280 set_next_rotation_time();
282 /* main worker loop */
283 for (;;)
285 bool time_based_rotation = false;
286 int size_rotation_for = 0;
288 #ifndef WIN32
289 int bytesRead;
290 int rc;
291 fd_set rfds;
292 struct timeval timeout;
293 #endif
295 if (got_SIGHUP)
297 got_SIGHUP = false;
298 ProcessConfigFile(PGC_SIGHUP);
301 * Check if the log directory or filename pattern changed in
302 * postgresql.conf. If so, force rotation to make sure we're
303 * writing the logfiles in the right place.
305 if (strcmp(Log_directory, currentLogDir) != 0)
307 pfree(currentLogDir);
308 currentLogDir = pstrdup(Log_directory);
309 rotation_requested = true;
311 if (strcmp(Log_filename, currentLogFilename) != 0)
313 pfree(currentLogFilename);
314 currentLogFilename = pstrdup(Log_filename);
315 rotation_requested = true;
319 * If rotation time parameter changed, reset next rotation time,
320 * but don't immediately force a rotation.
322 if (currentLogRotationAge != Log_RotationAge)
324 currentLogRotationAge = Log_RotationAge;
325 set_next_rotation_time();
329 if (!rotation_requested && Log_RotationAge > 0)
331 /* Do a logfile rotation if it's time */
332 pg_time_t now = (pg_time_t) time(NULL);
334 if (now >= next_rotation_time)
335 rotation_requested = time_based_rotation = true;
338 if (!rotation_requested && Log_RotationSize > 0)
340 /* Do a rotation if file is too big */
341 if (ftell(syslogFile) >= Log_RotationSize * 1024L)
343 rotation_requested = true;
344 size_rotation_for |= LOG_DESTINATION_STDERR;
346 if (csvlogFile != NULL &&
347 ftell(csvlogFile) >= Log_RotationSize * 1024L)
349 rotation_requested = true;
350 size_rotation_for |= LOG_DESTINATION_CSVLOG;
354 if (rotation_requested)
357 * Force rotation when both values are zero. It means the request
358 * was sent by pg_rotate_logfile.
360 if (!time_based_rotation && size_rotation_for == 0)
361 size_rotation_for = LOG_DESTINATION_STDERR | LOG_DESTINATION_CSVLOG;
362 logfile_rotate(time_based_rotation, size_rotation_for);
365 #ifndef WIN32
368 * Wait for some data, timing out after 1 second
370 FD_ZERO(&rfds);
371 FD_SET (syslogPipe[0], &rfds);
373 timeout.tv_sec = 1;
374 timeout.tv_usec = 0;
376 rc = select(syslogPipe[0] + 1, &rfds, NULL, NULL, &timeout);
378 if (rc < 0)
380 if (errno != EINTR)
381 ereport(LOG,
382 (errcode_for_socket_access(),
383 errmsg("select() failed in logger process: %m")));
385 else if (rc > 0 && FD_ISSET(syslogPipe[0], &rfds))
387 bytesRead = piperead(syslogPipe[0],
388 logbuffer + bytes_in_logbuffer,
389 sizeof(logbuffer) - bytes_in_logbuffer);
390 if (bytesRead < 0)
392 if (errno != EINTR)
393 ereport(LOG,
394 (errcode_for_socket_access(),
395 errmsg("could not read from logger pipe: %m")));
397 else if (bytesRead > 0)
399 bytes_in_logbuffer += bytesRead;
400 process_pipe_input(logbuffer, &bytes_in_logbuffer);
401 continue;
403 else
406 * Zero bytes read when select() is saying read-ready means
407 * EOF on the pipe: that is, there are no longer any processes
408 * with the pipe write end open. Therefore, the postmaster
409 * and all backends are shut down, and we are done.
411 pipe_eof_seen = true;
413 /* if there's any data left then force it out now */
414 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
417 #else /* WIN32 */
420 * On Windows we leave it to a separate thread to transfer data and
421 * detect pipe EOF. The main thread just wakes up once a second to
422 * check for SIGHUP and rotation conditions.
424 pg_usleep(1000000L);
425 #endif /* WIN32 */
427 if (pipe_eof_seen)
430 * seeing this message on the real stderr is annoying - so we make
431 * it DEBUG1 to suppress in normal use.
433 ereport(DEBUG1,
434 (errmsg("logger shutting down")));
437 * Normal exit from the syslogger is here. Note that we
438 * deliberately do not close syslogFile before exiting; this is to
439 * allow for the possibility of elog messages being generated
440 * inside proc_exit. Regular exit() will take care of flushing
441 * and closing stdio channels.
443 proc_exit(0);
449 * Postmaster subroutine to start a syslogger subprocess.
452 SysLogger_Start(void)
454 pid_t sysloggerPid;
455 char *filename;
457 if (!Logging_collector)
458 return 0;
461 * If first time through, create the pipe which will receive stderr
462 * output.
464 * If the syslogger crashes and needs to be restarted, we continue to use
465 * the same pipe (indeed must do so, since extant backends will be writing
466 * into that pipe).
468 * This means the postmaster must continue to hold the read end of the
469 * pipe open, so we can pass it down to the reincarnated syslogger. This
470 * is a bit klugy but we have little choice.
472 #ifndef WIN32
473 if (syslogPipe[0] < 0)
475 if (pgpipe(syslogPipe) < 0)
476 ereport(FATAL,
477 (errcode_for_socket_access(),
478 (errmsg("could not create pipe for syslog: %m"))));
480 #else
481 if (!syslogPipe[0])
483 SECURITY_ATTRIBUTES sa;
485 memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
486 sa.nLength = sizeof(SECURITY_ATTRIBUTES);
487 sa.bInheritHandle = TRUE;
489 if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
490 ereport(FATAL,
491 (errcode_for_file_access(),
492 (errmsg("could not create pipe for syslog: %m"))));
494 #endif
497 * Create log directory if not present; ignore errors
499 mkdir(Log_directory, 0700);
502 * The initial logfile is created right in the postmaster, to verify that
503 * the Log_directory is writable.
505 filename = logfile_getname(time(NULL), NULL);
507 syslogFile = fopen(filename, "a");
509 if (!syslogFile)
510 ereport(FATAL,
511 (errcode_for_file_access(),
512 (errmsg("could not create log file \"%s\": %m",
513 filename))));
515 setvbuf(syslogFile, NULL, LBF_MODE, 0);
517 pfree(filename);
519 #ifdef EXEC_BACKEND
520 switch ((sysloggerPid = syslogger_forkexec()))
521 #else
522 switch ((sysloggerPid = fork_process()))
523 #endif
525 case -1:
526 ereport(LOG,
527 (errmsg("could not fork system logger: %m")));
528 return 0;
530 #ifndef EXEC_BACKEND
531 case 0:
532 /* in postmaster child ... */
533 /* Close the postmaster's sockets */
534 ClosePostmasterPorts(true);
536 /* Lose the postmaster's on-exit routines */
537 on_exit_reset();
539 /* Drop our connection to postmaster's shared memory, as well */
540 PGSharedMemoryDetach();
542 /* do the work */
543 SysLoggerMain(0, NULL);
544 break;
545 #endif
547 default:
548 /* success, in postmaster */
550 /* now we redirect stderr, if not done already */
551 if (!redirection_done)
553 #ifndef WIN32
554 fflush(stdout);
555 if (dup2(syslogPipe[1], fileno(stdout)) < 0)
556 ereport(FATAL,
557 (errcode_for_file_access(),
558 errmsg("could not redirect stdout: %m")));
559 fflush(stderr);
560 if (dup2(syslogPipe[1], fileno(stderr)) < 0)
561 ereport(FATAL,
562 (errcode_for_file_access(),
563 errmsg("could not redirect stderr: %m")));
564 /* Now we are done with the write end of the pipe. */
565 close(syslogPipe[1]);
566 syslogPipe[1] = -1;
567 #else
568 int fd;
571 * open the pipe in binary mode and make sure stderr is binary
572 * after it's been dup'ed into, to avoid disturbing the pipe
573 * chunking protocol.
575 fflush(stderr);
576 fd = _open_osfhandle((long) syslogPipe[1],
577 _O_APPEND | _O_BINARY);
578 if (dup2(fd, _fileno(stderr)) < 0)
579 ereport(FATAL,
580 (errcode_for_file_access(),
581 errmsg("could not redirect stderr: %m")));
582 close(fd);
583 _setmode(_fileno(stderr), _O_BINARY);
584 /* Now we are done with the write end of the pipe. */
585 CloseHandle(syslogPipe[1]);
586 syslogPipe[1] = 0;
587 #endif
588 redirection_done = true;
591 /* postmaster will never write the file; close it */
592 fclose(syslogFile);
593 syslogFile = NULL;
594 return (int) sysloggerPid;
597 /* we should never reach here */
598 return 0;
602 #ifdef EXEC_BACKEND
605 * syslogger_forkexec() -
607 * Format up the arglist for, then fork and exec, a syslogger process
609 static pid_t
610 syslogger_forkexec(void)
612 char *av[10];
613 int ac = 0;
614 char filenobuf[32];
616 av[ac++] = "postgres";
617 av[ac++] = "--forklog";
618 av[ac++] = NULL; /* filled in by postmaster_forkexec */
620 /* static variables (those not passed by write_backend_variables) */
621 #ifndef WIN32
622 if (syslogFile != NULL)
623 snprintf(filenobuf, sizeof(filenobuf), "%d",
624 fileno(syslogFile));
625 else
626 strcpy(filenobuf, "-1");
627 #else /* WIN32 */
628 if (syslogFile != NULL)
629 snprintf(filenobuf, sizeof(filenobuf), "%ld",
630 _get_osfhandle(_fileno(syslogFile)));
631 else
632 strcpy(filenobuf, "0");
633 #endif /* WIN32 */
634 av[ac++] = filenobuf;
636 av[ac] = NULL;
637 Assert(ac < lengthof(av));
639 return postmaster_forkexec(ac, av);
643 * syslogger_parseArgs() -
645 * Extract data from the arglist for exec'ed syslogger process
647 static void
648 syslogger_parseArgs(int argc, char *argv[])
650 int fd;
652 Assert(argc == 4);
653 argv += 3;
655 #ifndef WIN32
656 fd = atoi(*argv++);
657 if (fd != -1)
659 syslogFile = fdopen(fd, "a");
660 setvbuf(syslogFile, NULL, LBF_MODE, 0);
662 #else /* WIN32 */
663 fd = atoi(*argv++);
664 if (fd != 0)
666 fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
667 if (fd > 0)
669 syslogFile = fdopen(fd, "a");
670 setvbuf(syslogFile, NULL, LBF_MODE, 0);
673 #endif /* WIN32 */
675 #endif /* EXEC_BACKEND */
678 /* --------------------------------
679 * pipe protocol handling
680 * --------------------------------
684 * Process data received through the syslogger pipe.
686 * This routine interprets the log pipe protocol which sends log messages as
687 * (hopefully atomic) chunks - such chunks are detected and reassembled here.
689 * The protocol has a header that starts with two nul bytes, then has a 16 bit
690 * length, the pid of the sending process, and a flag to indicate if it is
691 * the last chunk in a message. Incomplete chunks are saved until we read some
692 * more, and non-final chunks are accumulated until we get the final chunk.
694 * All of this is to avoid 2 problems:
695 * . partial messages being written to logfiles (messes rotation), and
696 * . messages from different backends being interleaved (messages garbled).
698 * Any non-protocol messages are written out directly. These should only come
699 * from non-PostgreSQL sources, however (e.g. third party libraries writing to
700 * stderr).
702 * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
703 * of bytes present. On exit, any not-yet-eaten data is left-justified in
704 * logbuffer, and *bytes_in_logbuffer is updated.
706 static void
707 process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
709 char *cursor = logbuffer;
710 int count = *bytes_in_logbuffer;
711 int dest = LOG_DESTINATION_STDERR;
713 /* While we have enough for a header, process data... */
714 while (count >= (int) sizeof(PipeProtoHeader))
716 PipeProtoHeader p;
717 int chunklen;
719 /* Do we have a valid header? */
720 memcpy(&p, cursor, sizeof(PipeProtoHeader));
721 if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
722 p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
723 p.pid != 0 &&
724 (p.is_last == 't' || p.is_last == 'f' ||
725 p.is_last == 'T' || p.is_last == 'F'))
727 chunklen = PIPE_HEADER_SIZE + p.len;
729 /* Fall out of loop if we don't have the whole chunk yet */
730 if (count < chunklen)
731 break;
733 dest = (p.is_last == 'T' || p.is_last == 'F') ?
734 LOG_DESTINATION_CSVLOG : LOG_DESTINATION_STDERR;
736 if (p.is_last == 'f' || p.is_last == 'F')
739 * Save a complete non-final chunk in the per-pid buffer if
740 * possible - if not just write it out.
742 int free_slot = -1,
743 existing_slot = -1;
744 int i;
745 StringInfo str;
747 for (i = 0; i < CHUNK_SLOTS; i++)
749 if (saved_chunks[i].pid == p.pid)
751 existing_slot = i;
752 break;
754 if (free_slot < 0 && saved_chunks[i].pid == 0)
755 free_slot = i;
757 if (existing_slot >= 0)
759 str = &(saved_chunks[existing_slot].data);
760 appendBinaryStringInfo(str,
761 cursor + PIPE_HEADER_SIZE,
762 p.len);
764 else if (free_slot >= 0)
766 saved_chunks[free_slot].pid = p.pid;
767 str = &(saved_chunks[free_slot].data);
768 initStringInfo(str);
769 appendBinaryStringInfo(str,
770 cursor + PIPE_HEADER_SIZE,
771 p.len);
773 else
776 * If there is no free slot we'll just have to take our
777 * chances and write out a partial message and hope that
778 * it's not followed by something from another pid.
780 write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
781 dest);
784 else
787 * Final chunk --- add it to anything saved for that pid, and
788 * either way write the whole thing out.
790 int existing_slot = -1;
791 int i;
792 StringInfo str;
794 for (i = 0; i < CHUNK_SLOTS; i++)
796 if (saved_chunks[i].pid == p.pid)
798 existing_slot = i;
799 break;
802 if (existing_slot >= 0)
804 str = &(saved_chunks[existing_slot].data);
805 appendBinaryStringInfo(str,
806 cursor + PIPE_HEADER_SIZE,
807 p.len);
808 write_syslogger_file(str->data, str->len, dest);
809 saved_chunks[existing_slot].pid = 0;
810 pfree(str->data);
812 else
814 /* The whole message was one chunk, evidently. */
815 write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
816 dest);
820 /* Finished processing this chunk */
821 cursor += chunklen;
822 count -= chunklen;
824 else
826 /* Process non-protocol data */
829 * Look for the start of a protocol header. If found, dump data
830 * up to there and repeat the loop. Otherwise, dump it all and
831 * fall out of the loop. (Note: we want to dump it all if at all
832 * possible, so as to avoid dividing non-protocol messages across
833 * logfiles. We expect that in many scenarios, a non-protocol
834 * message will arrive all in one read(), and we want to respect
835 * the read() boundary if possible.)
837 for (chunklen = 1; chunklen < count; chunklen++)
839 if (cursor[chunklen] == '\0')
840 break;
842 /* fall back on the stderr log as the destination */
843 write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
844 cursor += chunklen;
845 count -= chunklen;
849 /* We don't have a full chunk, so left-align what remains in the buffer */
850 if (count > 0 && cursor != logbuffer)
851 memmove(logbuffer, cursor, count);
852 *bytes_in_logbuffer = count;
856 * Force out any buffered data
858 * This is currently used only at syslogger shutdown, but could perhaps be
859 * useful at other times, so it is careful to leave things in a clean state.
861 static void
862 flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
864 int i;
865 StringInfo str;
867 /* Dump any incomplete protocol messages */
868 for (i = 0; i < CHUNK_SLOTS; i++)
870 if (saved_chunks[i].pid != 0)
872 str = &(saved_chunks[i].data);
873 write_syslogger_file(str->data, str->len, LOG_DESTINATION_STDERR);
874 saved_chunks[i].pid = 0;
875 pfree(str->data);
880 * Force out any remaining pipe data as-is; we don't bother trying to
881 * remove any protocol headers that may exist in it.
883 if (*bytes_in_logbuffer > 0)
884 write_syslogger_file(logbuffer, *bytes_in_logbuffer,
885 LOG_DESTINATION_STDERR);
886 *bytes_in_logbuffer = 0;
890 /* --------------------------------
891 * logfile routines
892 * --------------------------------
896 * Write text to the currently open logfile
898 * This is exported so that elog.c can call it when am_syslogger is true.
899 * This allows the syslogger process to record elog messages of its own,
900 * even though its stderr does not point at the syslog pipe.
902 void
903 write_syslogger_file(const char *buffer, int count, int destination)
905 int rc;
906 FILE *logfile;
908 if (destination == LOG_DESTINATION_CSVLOG && csvlogFile == NULL)
909 open_csvlogfile();
911 #ifdef WIN32
912 EnterCriticalSection(&sysfileSection);
913 #endif
915 logfile = destination == LOG_DESTINATION_CSVLOG ? csvlogFile : syslogFile;
916 rc = fwrite(buffer, 1, count, logfile);
918 #ifdef WIN32
919 LeaveCriticalSection(&sysfileSection);
920 #endif
922 /* can't use ereport here because of possible recursion */
923 if (rc != count)
924 write_stderr("could not write to log file: %s\n", strerror(errno));
927 #ifdef WIN32
930 * Worker thread to transfer data from the pipe to the current logfile.
932 * We need this because on Windows, WaitForSingleObject does not work on
933 * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
934 * allow for SIGHUP; and select is for sockets only.
936 static unsigned int __stdcall
937 pipeThread(void *arg)
939 char logbuffer[READ_BUF_SIZE];
940 int bytes_in_logbuffer = 0;
942 for (;;)
944 DWORD bytesRead;
946 if (!ReadFile(syslogPipe[0],
947 logbuffer + bytes_in_logbuffer,
948 sizeof(logbuffer) - bytes_in_logbuffer,
949 &bytesRead, 0))
951 DWORD error = GetLastError();
953 if (error == ERROR_HANDLE_EOF ||
954 error == ERROR_BROKEN_PIPE)
955 break;
956 _dosmaperr(error);
957 ereport(LOG,
958 (errcode_for_file_access(),
959 errmsg("could not read from logger pipe: %m")));
961 else if (bytesRead > 0)
963 bytes_in_logbuffer += bytesRead;
964 process_pipe_input(logbuffer, &bytes_in_logbuffer);
968 /* We exit the above loop only upon detecting pipe EOF */
969 pipe_eof_seen = true;
971 /* if there's any data left then force it out now */
972 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
974 _endthread();
975 return 0;
977 #endif /* WIN32 */
980 * open the csv log file - we do this opportunistically, because
981 * we don't know if CSV logging will be wanted.
983 static void
984 open_csvlogfile(void)
986 char *filename;
987 FILE *fh;
989 filename = logfile_getname(time(NULL), ".csv");
991 fh = fopen(filename, "a");
993 if (!fh)
994 ereport(FATAL,
995 (errcode_for_file_access(),
996 (errmsg("could not create log file \"%s\": %m",
997 filename))));
999 setvbuf(fh, NULL, LBF_MODE, 0);
1001 #ifdef WIN32
1002 _setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
1003 #endif
1005 csvlogFile = fh;
1007 pfree(filename);
1012 * perform logfile rotation
1014 static void
1015 logfile_rotate(bool time_based_rotation, int size_rotation_for)
1017 char *filename;
1018 char *csvfilename = NULL;
1019 FILE *fh;
1021 rotation_requested = false;
1024 * When doing a time-based rotation, invent the new logfile name based on
1025 * the planned rotation time, not current time, to avoid "slippage" in the
1026 * file name when we don't do the rotation immediately.
1028 if (time_based_rotation)
1030 filename = logfile_getname(next_rotation_time, NULL);
1031 if (csvlogFile != NULL)
1032 csvfilename = logfile_getname(next_rotation_time, ".csv");
1034 else
1036 filename = logfile_getname(time(NULL), NULL);
1037 if (csvlogFile != NULL)
1038 csvfilename = logfile_getname(time(NULL), ".csv");
1042 * Decide whether to overwrite or append. We can overwrite if (a)
1043 * Log_truncate_on_rotation is set, (b) the rotation was triggered by
1044 * elapsed time and not something else, and (c) the computed file name is
1045 * different from what we were previously logging into.
1047 * Note: during the first rotation after forking off from the postmaster,
1048 * last_file_name will be NULL. (We don't bother to set it in the
1049 * postmaster because it ain't gonna work in the EXEC_BACKEND case.) So we
1050 * will always append in that situation, even though truncating would
1051 * usually be safe.
1053 * For consistency, we treat CSV logs the same even though they aren't
1054 * opened in the postmaster.
1056 if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
1058 if (Log_truncate_on_rotation && time_based_rotation &&
1059 last_file_name != NULL &&
1060 strcmp(filename, last_file_name) != 0)
1061 fh = fopen(filename, "w");
1062 else
1063 fh = fopen(filename, "a");
1065 if (!fh)
1067 int saveerrno = errno;
1069 ereport(LOG,
1070 (errcode_for_file_access(),
1071 errmsg("could not open new log file \"%s\": %m",
1072 filename)));
1075 * ENFILE/EMFILE are not too surprising on a busy system; just
1076 * keep using the old file till we manage to get a new one.
1077 * Otherwise, assume something's wrong with Log_directory and stop
1078 * trying to create files.
1080 if (saveerrno != ENFILE && saveerrno != EMFILE)
1082 ereport(LOG,
1083 (errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
1084 Log_RotationAge = 0;
1085 Log_RotationSize = 0;
1087 pfree(filename);
1088 if (csvfilename)
1089 pfree(csvfilename);
1090 return;
1093 setvbuf(fh, NULL, LBF_MODE, 0);
1095 #ifdef WIN32
1096 _setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
1097 #endif
1099 /* On Windows, need to interlock against data-transfer thread */
1100 #ifdef WIN32
1101 EnterCriticalSection(&sysfileSection);
1102 #endif
1103 fclose(syslogFile);
1104 syslogFile = fh;
1105 #ifdef WIN32
1106 LeaveCriticalSection(&sysfileSection);
1107 #endif
1109 /* instead of pfree'ing filename, remember it for next time */
1110 if (last_file_name != NULL)
1111 pfree(last_file_name);
1112 last_file_name = filename;
1115 /* Same as above, but for csv file. */
1117 if (csvlogFile != NULL &&
1118 (time_based_rotation || (size_rotation_for & LOG_DESTINATION_CSVLOG)))
1120 if (Log_truncate_on_rotation && time_based_rotation &&
1121 last_csv_file_name != NULL &&
1122 strcmp(csvfilename, last_csv_file_name) != 0)
1123 fh = fopen(csvfilename, "w");
1124 else
1125 fh = fopen(csvfilename, "a");
1127 if (!fh)
1129 int saveerrno = errno;
1131 ereport(LOG,
1132 (errcode_for_file_access(),
1133 errmsg("could not open new log file \"%s\": %m",
1134 csvfilename)));
1137 * ENFILE/EMFILE are not too surprising on a busy system; just
1138 * keep using the old file till we manage to get a new one.
1139 * Otherwise, assume something's wrong with Log_directory and stop
1140 * trying to create files.
1142 if (saveerrno != ENFILE && saveerrno != EMFILE)
1144 ereport(LOG,
1145 (errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
1146 Log_RotationAge = 0;
1147 Log_RotationSize = 0;
1149 pfree(csvfilename);
1150 return;
1153 setvbuf(fh, NULL, LBF_MODE, 0);
1155 #ifdef WIN32
1156 _setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
1157 #endif
1159 /* On Windows, need to interlock against data-transfer thread */
1160 #ifdef WIN32
1161 EnterCriticalSection(&sysfileSection);
1162 #endif
1163 fclose(csvlogFile);
1164 csvlogFile = fh;
1165 #ifdef WIN32
1166 LeaveCriticalSection(&sysfileSection);
1167 #endif
1169 /* instead of pfree'ing filename, remember it for next time */
1170 if (last_csv_file_name != NULL)
1171 pfree(last_csv_file_name);
1172 last_csv_file_name = csvfilename;
1175 set_next_rotation_time();
1180 * construct logfile name using timestamp information
1182 * Result is palloc'd.
1184 static char *
1185 logfile_getname(pg_time_t timestamp, char *suffix)
1187 char *filename;
1188 int len;
1190 filename = palloc(MAXPGPATH);
1192 snprintf(filename, MAXPGPATH, "%s/", Log_directory);
1194 len = strlen(filename);
1196 /* treat it as a strftime pattern */
1197 pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
1198 pg_localtime(&timestamp, log_timezone));
1200 if (suffix != NULL)
1202 len = strlen(filename);
1203 if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
1204 len -= 4;
1205 strncpy(filename + len, suffix, MAXPGPATH - len);
1208 return filename;
1212 * Determine the next planned rotation time, and store in next_rotation_time.
1214 static void
1215 set_next_rotation_time(void)
1217 pg_time_t now;
1218 struct pg_tm *tm;
1219 int rotinterval;
1221 /* nothing to do if time-based rotation is disabled */
1222 if (Log_RotationAge <= 0)
1223 return;
1226 * The requirements here are to choose the next time > now that is a
1227 * "multiple" of the log rotation interval. "Multiple" can be interpreted
1228 * fairly loosely. In this version we align to log_timezone rather than
1229 * GMT.
1231 rotinterval = Log_RotationAge * SECS_PER_MINUTE; /* convert to seconds */
1232 now = (pg_time_t) time(NULL);
1233 tm = pg_localtime(&now, log_timezone);
1234 now += tm->tm_gmtoff;
1235 now -= now % rotinterval;
1236 now += rotinterval;
1237 now -= tm->tm_gmtoff;
1238 next_rotation_time = now;
1241 /* --------------------------------
1242 * signal handler routines
1243 * --------------------------------
1246 /* SIGHUP: set flag to reload config file */
1247 static void
1248 sigHupHandler(SIGNAL_ARGS)
1250 got_SIGHUP = true;
1253 /* SIGUSR1: set flag to rotate logfile */
1254 static void
1255 sigUsr1Handler(SIGNAL_ARGS)
1257 rotation_requested = true;