1 /*-------------------------------------------------------------------------
5 * The system logger (syslogger) appeared 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 a user-selectable naming scheme.
14 * Author: Andreas Pflug <pgadmin@pse-consulting.de>
16 * Copyright (c) 2004-2013, PostgreSQL Global Development Group
20 * src/backend/postmaster/syslogger.c
22 *-------------------------------------------------------------------------
34 #include "lib/stringinfo.h"
35 #include "libpq/pqsignal.h"
36 #include "miscadmin.h"
37 #include "nodes/pg_list.h"
39 #include "postmaster/fork_process.h"
40 #include "postmaster/postmaster.h"
41 #include "postmaster/syslogger.h"
42 #include "storage/ipc.h"
43 #include "storage/latch.h"
44 #include "storage/pg_shmem.h"
45 #include "utils/guc.h"
46 #include "utils/ps_status.h"
47 #include "utils/timestamp.h"
50 * We really want line-buffered mode for logfile output, but Windows does
51 * not have it, and interprets _IOLBF as _IOFBF (bozos). So use _IONBF
55 #define LBF_MODE _IONBF
57 #define LBF_MODE _IOLBF
61 * We read() into a temp buffer twice as big as a chunk, so that any fragment
62 * left after processing can be moved down to the front and we'll still have
63 * room to read a full chunk.
65 #define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)
69 * GUC parameters. Logging_collector cannot be changed after postmaster
70 * start, but the rest can change at SIGHUP.
72 bool Logging_collector = false;
73 int Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
74 int Log_RotationSize = 10 * 1024;
75 char *Log_directory = NULL;
76 char *Log_filename = NULL;
77 bool Log_truncate_on_rotation = false;
78 int Log_file_mode = S_IRUSR | S_IWUSR;
81 * Globally visible state (used by elog.c)
83 bool am_syslogger = false;
85 extern bool redirection_done;
90 static pg_time_t next_rotation_time;
91 static bool pipe_eof_seen = false;
92 static bool rotation_disabled = false;
93 static FILE *syslogFile = NULL;
94 static FILE *csvlogFile = NULL;
95 NON_EXEC_STATIC pg_time_t first_syslogger_file_time = 0;
96 static char *last_file_name = NULL;
97 static char *last_csv_file_name = NULL;
98 static Latch sysLoggerLatch;
101 * Buffers for saving partial messages from different backends.
103 * Keep NBUFFER_LISTS lists of these, with the entry for a given source pid
104 * being in the list numbered (pid % NBUFFER_LISTS), so as to cut down on
105 * the number of entries we have to examine for any one incoming message.
106 * There must never be more than one entry for the same source pid.
108 * An inactive buffer is not removed from its list, just held for re-use.
109 * An inactive buffer has pid == 0 and undefined contents of data.
113 int32 pid; /* PID of source process */
114 StringInfoData data; /* accumulated data, as a StringInfo */
117 #define NBUFFER_LISTS 256
118 static List *buffer_lists[NBUFFER_LISTS];
120 /* These must be exported for EXEC_BACKEND case ... annoying */
122 int syslogPipe[2] = {-1, -1};
124 HANDLE syslogPipe[2] = {0, 0};
128 static HANDLE threadHandle = 0;
129 static CRITICAL_SECTION sysloggerSection;
133 * Flags set by interrupt handlers for later service in the main loop.
135 static volatile sig_atomic_t got_SIGHUP = false;
136 static volatile sig_atomic_t rotation_requested = false;
139 /* Local subroutines */
141 static pid_t syslogger_forkexec(void);
142 static void syslogger_parseArgs(int argc, char *argv[]);
144 NON_EXEC_STATIC void SysLoggerMain(int argc, char *argv[]) __attribute__((noreturn));
145 static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
146 static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
147 static void open_csvlogfile(void);
148 static FILE *logfile_open(const char *filename, const char *mode,
152 static unsigned int __stdcall pipeThread(void *arg);
154 static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
155 static char *logfile_getname(pg_time_t timestamp, const char *suffix);
156 static void set_next_rotation_time(void);
157 static void sigHupHandler(SIGNAL_ARGS);
158 static void sigUsr1Handler(SIGNAL_ARGS);
162 * Main entry point for syslogger process
163 * argc/argv parameters are valid only in EXEC_BACKEND case.
166 SysLoggerMain(int argc, char *argv[])
169 char logbuffer[READ_BUF_SIZE];
170 int bytes_in_logbuffer = 0;
173 char *currentLogFilename;
174 int currentLogRotationAge;
177 IsUnderPostmaster = true; /* we are a postmaster subprocess now */
179 MyProcPid = getpid(); /* reset MyProcPid */
181 MyStartTime = time(NULL); /* set our start time in case we call elog */
185 syslogger_parseArgs(argc, argv);
186 #endif /* EXEC_BACKEND */
190 init_ps_display("logger process", "", "", "");
193 * If we restarted, our stderr is already redirected into our own input
194 * pipe. This is of course pretty useless, not to mention that it
195 * interferes with detecting pipe EOF. Point stderr to /dev/null. This
196 * assumes that all interesting messages generated in the syslogger will
197 * come through elog.c and will be sent to write_syslogger_file.
199 if (redirection_done)
201 int fd = open(DEVNULL, O_WRONLY, 0);
204 * The closes might look redundant, but they are not: we want to be
205 * darn sure the pipe gets closed even if the open failed. We can
206 * survive running with stderr pointing nowhere, but we can't afford
207 * to have extra pipe input descriptors hanging around.
209 close(fileno(stdout));
210 close(fileno(stderr));
213 dup2(fd, fileno(stdout));
214 dup2(fd, fileno(stderr));
220 * Syslogger's own stderr can't be the syslogPipe, so set it back to text
221 * mode if we didn't just close it. (It was set to binary in
222 * SubPostmasterMain).
226 _setmode(_fileno(stderr), _O_TEXT);
230 * Also close our copy of the write end of the pipe. This is needed to
231 * ensure we can detect pipe EOF correctly. (But note that in the restart
232 * case, the postmaster already did this.)
235 if (syslogPipe[1] >= 0)
236 close(syslogPipe[1]);
240 CloseHandle(syslogPipe[1]);
245 * If possible, make this process a group leader, so that the postmaster
246 * can signal any child processes too. (syslogger probably never has any
247 * child processes, but for consistency we make all postmaster child
248 * processes do this.)
252 elog(FATAL, "setsid() failed: %m");
255 InitializeLatchSupport(); /* needed for latch waits */
257 /* Initialize private latch for use by signal handlers */
258 InitLatch(&sysLoggerLatch);
261 * Properly accept or ignore signals the postmaster might send us
263 * Note: we ignore all termination signals, and instead exit only when all
264 * upstream processes are gone, to ensure we don't miss any dying gasps of
268 pqsignal(SIGHUP, sigHupHandler); /* set flag to read config file */
269 pqsignal(SIGINT, SIG_IGN);
270 pqsignal(SIGTERM, SIG_IGN);
271 pqsignal(SIGQUIT, SIG_IGN);
272 pqsignal(SIGALRM, SIG_IGN);
273 pqsignal(SIGPIPE, SIG_IGN);
274 pqsignal(SIGUSR1, sigUsr1Handler); /* request log rotation */
275 pqsignal(SIGUSR2, SIG_IGN);
278 * Reset some signals that are accepted by postmaster but not here
280 pqsignal(SIGCHLD, SIG_DFL);
281 pqsignal(SIGTTIN, SIG_DFL);
282 pqsignal(SIGTTOU, SIG_DFL);
283 pqsignal(SIGCONT, SIG_DFL);
284 pqsignal(SIGWINCH, SIG_DFL);
286 PG_SETMASK(&UnBlockSig);
289 /* Fire up separate data transfer thread */
290 InitializeCriticalSection(&sysloggerSection);
291 EnterCriticalSection(&sysloggerSection);
293 threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
294 if (threadHandle == 0)
295 elog(FATAL, "could not create syslogger data transfer thread: %m");
299 * Remember active logfile's name. We recompute this from the reference
300 * time because passing down just the pg_time_t is a lot cheaper than
301 * passing a whole file path in the EXEC_BACKEND case.
303 last_file_name = logfile_getname(first_syslogger_file_time, NULL);
305 /* remember active logfile parameters */
306 currentLogDir = pstrdup(Log_directory);
307 currentLogFilename = pstrdup(Log_filename);
308 currentLogRotationAge = Log_RotationAge;
309 /* set next planned rotation time */
310 set_next_rotation_time();
312 /* main worker loop */
315 bool time_based_rotation = false;
316 int size_rotation_for = 0;
324 /* Clear any already-pending wakeups */
325 ResetLatch(&sysLoggerLatch);
328 * Process any requests or signals received recently.
333 ProcessConfigFile(PGC_SIGHUP);
336 * Check if the log directory or filename pattern changed in
337 * postgresql.conf. If so, force rotation to make sure we're
338 * writing the logfiles in the right place.
340 if (strcmp(Log_directory, currentLogDir) != 0)
342 pfree(currentLogDir);
343 currentLogDir = pstrdup(Log_directory);
344 rotation_requested = true;
347 * Also, create new directory if not present; ignore errors
349 mkdir(Log_directory, S_IRWXU);
351 if (strcmp(Log_filename, currentLogFilename) != 0)
353 pfree(currentLogFilename);
354 currentLogFilename = pstrdup(Log_filename);
355 rotation_requested = true;
359 * If rotation time parameter changed, reset next rotation time,
360 * but don't immediately force a rotation.
362 if (currentLogRotationAge != Log_RotationAge)
364 currentLogRotationAge = Log_RotationAge;
365 set_next_rotation_time();
369 * If we had a rotation-disabling failure, re-enable rotation
370 * attempts after SIGHUP, and force one immediately.
372 if (rotation_disabled)
374 rotation_disabled = false;
375 rotation_requested = true;
379 if (Log_RotationAge > 0 && !rotation_disabled)
381 /* Do a logfile rotation if it's time */
382 now = (pg_time_t) time(NULL);
383 if (now >= next_rotation_time)
384 rotation_requested = time_based_rotation = true;
387 if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
389 /* Do a rotation if file is too big */
390 if (ftell(syslogFile) >= Log_RotationSize * 1024L)
392 rotation_requested = true;
393 size_rotation_for |= LOG_DESTINATION_STDERR;
395 if (csvlogFile != NULL &&
396 ftell(csvlogFile) >= Log_RotationSize * 1024L)
398 rotation_requested = true;
399 size_rotation_for |= LOG_DESTINATION_CSVLOG;
403 if (rotation_requested)
406 * Force rotation when both values are zero. It means the request
407 * was sent by pg_rotate_logfile.
409 if (!time_based_rotation && size_rotation_for == 0)
410 size_rotation_for = LOG_DESTINATION_STDERR | LOG_DESTINATION_CSVLOG;
411 logfile_rotate(time_based_rotation, size_rotation_for);
415 * Calculate time till next time-based rotation, so that we don't
416 * sleep longer than that. We assume the value of "now" obtained
417 * above is still close enough. Note we can't make this calculation
418 * until after calling logfile_rotate(), since it will advance
419 * next_rotation_time.
421 * Also note that we need to beware of overflow in calculation of the
422 * timeout: with large settings of Log_RotationAge, next_rotation_time
423 * could be more than INT_MAX msec in the future. In that case we'll
424 * wait no more than INT_MAX msec, and try again.
426 if (Log_RotationAge > 0 && !rotation_disabled)
430 delay = next_rotation_time - now;
433 if (delay > INT_MAX / 1000)
434 delay = INT_MAX / 1000;
435 cur_timeout = delay * 1000L; /* msec */
439 cur_flags = WL_TIMEOUT;
448 * Sleep until there's something to do
451 rc = WaitLatchOrSocket(&sysLoggerLatch,
452 WL_LATCH_SET | WL_SOCKET_READABLE | cur_flags,
456 if (rc & WL_SOCKET_READABLE)
460 bytesRead = read(syslogPipe[0],
461 logbuffer + bytes_in_logbuffer,
462 sizeof(logbuffer) - bytes_in_logbuffer);
467 (errcode_for_socket_access(),
468 errmsg("could not read from logger pipe: %m")));
470 else if (bytesRead > 0)
472 bytes_in_logbuffer += bytesRead;
473 process_pipe_input(logbuffer, &bytes_in_logbuffer);
479 * Zero bytes read when select() is saying read-ready means
480 * EOF on the pipe: that is, there are no longer any processes
481 * with the pipe write end open. Therefore, the postmaster
482 * and all backends are shut down, and we are done.
484 pipe_eof_seen = true;
486 /* if there's any data left then force it out now */
487 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
493 * On Windows we leave it to a separate thread to transfer data and
494 * detect pipe EOF. The main thread just wakes up to handle SIGHUP
495 * and rotation conditions.
497 * Server code isn't generally thread-safe, so we ensure that only one
498 * of the threads is active at a time by entering the critical section
499 * whenever we're not sleeping.
501 LeaveCriticalSection(&sysloggerSection);
503 (void) WaitLatch(&sysLoggerLatch,
504 WL_LATCH_SET | cur_flags,
507 EnterCriticalSection(&sysloggerSection);
513 * seeing this message on the real stderr is annoying - so we make
514 * it DEBUG1 to suppress in normal use.
517 (errmsg("logger shutting down")));
520 * Normal exit from the syslogger is here. Note that we
521 * deliberately do not close syslogFile before exiting; this is to
522 * allow for the possibility of elog messages being generated
523 * inside proc_exit. Regular exit() will take care of flushing
524 * and closing stdio channels.
532 * Postmaster subroutine to start a syslogger subprocess.
535 SysLogger_Start(void)
540 if (!Logging_collector)
544 * If first time through, create the pipe which will receive stderr
547 * If the syslogger crashes and needs to be restarted, we continue to use
548 * the same pipe (indeed must do so, since extant backends will be writing
551 * This means the postmaster must continue to hold the read end of the
552 * pipe open, so we can pass it down to the reincarnated syslogger. This
553 * is a bit klugy but we have little choice.
556 if (syslogPipe[0] < 0)
558 if (pipe(syslogPipe) < 0)
560 (errcode_for_socket_access(),
561 (errmsg("could not create pipe for syslog: %m"))));
566 SECURITY_ATTRIBUTES sa;
568 memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
569 sa.nLength = sizeof(SECURITY_ATTRIBUTES);
570 sa.bInheritHandle = TRUE;
572 if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
574 (errcode_for_file_access(),
575 (errmsg("could not create pipe for syslog: %m"))));
580 * Create log directory if not present; ignore errors
582 mkdir(Log_directory, S_IRWXU);
585 * The initial logfile is created right in the postmaster, to verify that
586 * the Log_directory is writable. We save the reference time so that
587 * the syslogger child process can recompute this file name.
589 * It might look a bit strange to re-do this during a syslogger restart,
590 * but we must do so since the postmaster closed syslogFile after the
591 * previous fork (and remembering that old file wouldn't be right anyway).
592 * Note we always append here, we won't overwrite any existing file. This
593 * is consistent with the normal rules, because by definition this is not
594 * a time-based rotation.
596 first_syslogger_file_time = time(NULL);
597 filename = logfile_getname(first_syslogger_file_time, NULL);
599 syslogFile = logfile_open(filename, "a", false);
604 switch ((sysloggerPid = syslogger_forkexec()))
606 switch ((sysloggerPid = fork_process()))
611 (errmsg("could not fork system logger: %m")));
616 /* in postmaster child ... */
617 /* Close the postmaster's sockets */
618 ClosePostmasterPorts(true);
620 /* Lose the postmaster's on-exit routines */
623 /* Drop our connection to postmaster's shared memory, as well */
624 PGSharedMemoryDetach();
627 SysLoggerMain(0, NULL);
632 /* success, in postmaster */
634 /* now we redirect stderr, if not done already */
635 if (!redirection_done)
639 if (dup2(syslogPipe[1], fileno(stdout)) < 0)
641 (errcode_for_file_access(),
642 errmsg("could not redirect stdout: %m")));
644 if (dup2(syslogPipe[1], fileno(stderr)) < 0)
646 (errcode_for_file_access(),
647 errmsg("could not redirect stderr: %m")));
648 /* Now we are done with the write end of the pipe. */
649 close(syslogPipe[1]);
655 * open the pipe in binary mode and make sure stderr is binary
656 * after it's been dup'ed into, to avoid disturbing the pipe
660 fd = _open_osfhandle((intptr_t) syslogPipe[1],
661 _O_APPEND | _O_BINARY);
662 if (dup2(fd, _fileno(stderr)) < 0)
664 (errcode_for_file_access(),
665 errmsg("could not redirect stderr: %m")));
667 _setmode(_fileno(stderr), _O_BINARY);
670 * Now we are done with the write end of the pipe.
671 * CloseHandle() must not be called because the preceding
672 * close() closes the underlying handle.
676 redirection_done = true;
679 /* postmaster will never write the file; close it */
682 return (int) sysloggerPid;
685 /* we should never reach here */
693 * syslogger_forkexec() -
695 * Format up the arglist for, then fork and exec, a syslogger process
698 syslogger_forkexec(void)
704 av[ac++] = "postgres";
705 av[ac++] = "--forklog";
706 av[ac++] = NULL; /* filled in by postmaster_forkexec */
708 /* static variables (those not passed by write_backend_variables) */
710 if (syslogFile != NULL)
711 snprintf(filenobuf, sizeof(filenobuf), "%d",
714 strcpy(filenobuf, "-1");
716 if (syslogFile != NULL)
717 snprintf(filenobuf, sizeof(filenobuf), "%ld",
718 (long) _get_osfhandle(_fileno(syslogFile)));
720 strcpy(filenobuf, "0");
722 av[ac++] = filenobuf;
725 Assert(ac < lengthof(av));
727 return postmaster_forkexec(ac, av);
731 * syslogger_parseArgs() -
733 * Extract data from the arglist for exec'ed syslogger process
736 syslogger_parseArgs(int argc, char *argv[])
747 syslogFile = fdopen(fd, "a");
748 setvbuf(syslogFile, NULL, LBF_MODE, 0);
754 fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
757 syslogFile = fdopen(fd, "a");
758 setvbuf(syslogFile, NULL, LBF_MODE, 0);
763 #endif /* EXEC_BACKEND */
766 /* --------------------------------
767 * pipe protocol handling
768 * --------------------------------
772 * Process data received through the syslogger pipe.
774 * This routine interprets the log pipe protocol which sends log messages as
775 * (hopefully atomic) chunks - such chunks are detected and reassembled here.
777 * The protocol has a header that starts with two nul bytes, then has a 16 bit
778 * length, the pid of the sending process, and a flag to indicate if it is
779 * the last chunk in a message. Incomplete chunks are saved until we read some
780 * more, and non-final chunks are accumulated until we get the final chunk.
782 * All of this is to avoid 2 problems:
783 * . partial messages being written to logfiles (messes rotation), and
784 * . messages from different backends being interleaved (messages garbled).
786 * Any non-protocol messages are written out directly. These should only come
787 * from non-PostgreSQL sources, however (e.g. third party libraries writing to
790 * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
791 * of bytes present. On exit, any not-yet-eaten data is left-justified in
792 * logbuffer, and *bytes_in_logbuffer is updated.
795 process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
797 char *cursor = logbuffer;
798 int count = *bytes_in_logbuffer;
799 int dest = LOG_DESTINATION_STDERR;
801 /* While we have enough for a header, process data... */
802 while (count >= (int) sizeof(PipeProtoHeader))
807 /* Do we have a valid header? */
808 memcpy(&p, cursor, sizeof(PipeProtoHeader));
809 if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
810 p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
812 (p.is_last == 't' || p.is_last == 'f' ||
813 p.is_last == 'T' || p.is_last == 'F'))
817 save_buffer *existing_slot = NULL,
821 chunklen = PIPE_HEADER_SIZE + p.len;
823 /* Fall out of loop if we don't have the whole chunk yet */
824 if (count < chunklen)
827 dest = (p.is_last == 'T' || p.is_last == 'F') ?
828 LOG_DESTINATION_CSVLOG : LOG_DESTINATION_STDERR;
830 /* Locate any existing buffer for this source pid */
831 buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
832 foreach(cell, buffer_list)
834 save_buffer *buf = (save_buffer *) lfirst(cell);
836 if (buf->pid == p.pid)
841 if (buf->pid == 0 && free_slot == NULL)
845 if (p.is_last == 'f' || p.is_last == 'F')
848 * Save a complete non-final chunk in a per-pid buffer
850 if (existing_slot != NULL)
852 /* Add chunk to data from preceding chunks */
853 str = &(existing_slot->data);
854 appendBinaryStringInfo(str,
855 cursor + PIPE_HEADER_SIZE,
860 /* First chunk of message, save in a new buffer */
861 if (free_slot == NULL)
864 * Need a free slot, but there isn't one in the list,
865 * so create a new one and extend the list with it.
867 free_slot = palloc(sizeof(save_buffer));
868 buffer_list = lappend(buffer_list, free_slot);
869 buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
871 free_slot->pid = p.pid;
872 str = &(free_slot->data);
874 appendBinaryStringInfo(str,
875 cursor + PIPE_HEADER_SIZE,
882 * Final chunk --- add it to anything saved for that pid, and
883 * either way write the whole thing out.
885 if (existing_slot != NULL)
887 str = &(existing_slot->data);
888 appendBinaryStringInfo(str,
889 cursor + PIPE_HEADER_SIZE,
891 write_syslogger_file(str->data, str->len, dest);
892 /* Mark the buffer unused, and reclaim string storage */
893 existing_slot->pid = 0;
898 /* The whole message was one chunk, evidently. */
899 write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
904 /* Finished processing this chunk */
910 /* Process non-protocol data */
913 * Look for the start of a protocol header. If found, dump data
914 * up to there and repeat the loop. Otherwise, dump it all and
915 * fall out of the loop. (Note: we want to dump it all if at all
916 * possible, so as to avoid dividing non-protocol messages across
917 * logfiles. We expect that in many scenarios, a non-protocol
918 * message will arrive all in one read(), and we want to respect
919 * the read() boundary if possible.)
921 for (chunklen = 1; chunklen < count; chunklen++)
923 if (cursor[chunklen] == '\0')
926 /* fall back on the stderr log as the destination */
927 write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
933 /* We don't have a full chunk, so left-align what remains in the buffer */
934 if (count > 0 && cursor != logbuffer)
935 memmove(logbuffer, cursor, count);
936 *bytes_in_logbuffer = count;
940 * Force out any buffered data
942 * This is currently used only at syslogger shutdown, but could perhaps be
943 * useful at other times, so it is careful to leave things in a clean state.
946 flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
950 /* Dump any incomplete protocol messages */
951 for (i = 0; i < NBUFFER_LISTS; i++)
953 List *list = buffer_lists[i];
958 save_buffer *buf = (save_buffer *) lfirst(cell);
962 StringInfo str = &(buf->data);
964 write_syslogger_file(str->data, str->len,
965 LOG_DESTINATION_STDERR);
966 /* Mark the buffer unused, and reclaim string storage */
974 * Force out any remaining pipe data as-is; we don't bother trying to
975 * remove any protocol headers that may exist in it.
977 if (*bytes_in_logbuffer > 0)
978 write_syslogger_file(logbuffer, *bytes_in_logbuffer,
979 LOG_DESTINATION_STDERR);
980 *bytes_in_logbuffer = 0;
984 /* --------------------------------
986 * --------------------------------
990 * Write text to the currently open logfile
992 * This is exported so that elog.c can call it when am_syslogger is true.
993 * This allows the syslogger process to record elog messages of its own,
994 * even though its stderr does not point at the syslog pipe.
997 write_syslogger_file(const char *buffer, int count, int destination)
1002 if (destination == LOG_DESTINATION_CSVLOG && csvlogFile == NULL)
1005 logfile = destination == LOG_DESTINATION_CSVLOG ? csvlogFile : syslogFile;
1006 rc = fwrite(buffer, 1, count, logfile);
1008 /* can't use ereport here because of possible recursion */
1010 write_stderr("could not write to log file: %s\n", strerror(errno));
1016 * Worker thread to transfer data from the pipe to the current logfile.
1018 * We need this because on Windows, WaitforMultipleObjects does not work on
1019 * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
1020 * allow for SIGHUP; and select is for sockets only.
1022 static unsigned int __stdcall
1023 pipeThread(void *arg)
1025 char logbuffer[READ_BUF_SIZE];
1026 int bytes_in_logbuffer = 0;
1033 result = ReadFile(syslogPipe[0],
1034 logbuffer + bytes_in_logbuffer,
1035 sizeof(logbuffer) - bytes_in_logbuffer,
1039 * Enter critical section before doing anything that might touch
1040 * global state shared by the main thread. Anything that uses
1041 * palloc()/pfree() in particular are not safe outside the critical
1044 EnterCriticalSection(&sysloggerSection);
1047 DWORD error = GetLastError();
1049 if (error == ERROR_HANDLE_EOF ||
1050 error == ERROR_BROKEN_PIPE)
1054 (errcode_for_file_access(),
1055 errmsg("could not read from logger pipe: %m")));
1057 else if (bytesRead > 0)
1059 bytes_in_logbuffer += bytesRead;
1060 process_pipe_input(logbuffer, &bytes_in_logbuffer);
1064 * If we've filled the current logfile, nudge the main thread to do a
1067 if (Log_RotationSize > 0)
1069 if (ftell(syslogFile) >= Log_RotationSize * 1024L ||
1070 (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L))
1071 SetLatch(&sysLoggerLatch);
1073 LeaveCriticalSection(&sysloggerSection);
1076 /* We exit the above loop only upon detecting pipe EOF */
1077 pipe_eof_seen = true;
1079 /* if there's any data left then force it out now */
1080 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
1082 /* set the latch to waken the main thread, which will quit */
1083 SetLatch(&sysLoggerLatch);
1085 LeaveCriticalSection(&sysloggerSection);
1092 * Open the csv log file - we do this opportunistically, because
1093 * we don't know if CSV logging will be wanted.
1095 * This is only used the first time we open the csv log in a given syslogger
1096 * process, not during rotations. As with opening the main log file, we
1097 * always append in this situation.
1100 open_csvlogfile(void)
1104 filename = logfile_getname(time(NULL), ".csv");
1106 csvlogFile = logfile_open(filename, "a", false);
1108 if (last_csv_file_name != NULL) /* probably shouldn't happen */
1109 pfree(last_csv_file_name);
1111 last_csv_file_name = filename;
1115 * Open a new logfile with proper permissions and buffering options.
1117 * If allow_errors is true, we just log any open failure and return NULL
1118 * (with errno still correct for the fopen failure).
1119 * Otherwise, errors are treated as fatal.
1122 logfile_open(const char *filename, const char *mode, bool allow_errors)
1128 * Note we do not let Log_file_mode disable IWUSR, since we certainly want
1129 * to be able to write the files ourselves.
1131 oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
1132 fh = fopen(filename, mode);
1137 setvbuf(fh, NULL, LBF_MODE, 0);
1140 /* use CRLF line endings on Windows */
1141 _setmode(_fileno(fh), _O_TEXT);
1146 int save_errno = errno;
1148 ereport(allow_errors ? LOG : FATAL,
1149 (errcode_for_file_access(),
1150 errmsg("could not open log file \"%s\": %m",
1159 * perform logfile rotation
1162 logfile_rotate(bool time_based_rotation, int size_rotation_for)
1165 char *csvfilename = NULL;
1169 rotation_requested = false;
1172 * When doing a time-based rotation, invent the new logfile name based on
1173 * the planned rotation time, not current time, to avoid "slippage" in the
1174 * file name when we don't do the rotation immediately.
1176 if (time_based_rotation)
1177 fntime = next_rotation_time;
1179 fntime = time(NULL);
1180 filename = logfile_getname(fntime, NULL);
1181 if (csvlogFile != NULL)
1182 csvfilename = logfile_getname(fntime, ".csv");
1185 * Decide whether to overwrite or append. We can overwrite if (a)
1186 * Log_truncate_on_rotation is set, (b) the rotation was triggered by
1187 * elapsed time and not something else, and (c) the computed file name is
1188 * different from what we were previously logging into.
1190 * Note: last_file_name should never be NULL here, but if it is, append.
1192 if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
1194 if (Log_truncate_on_rotation && time_based_rotation &&
1195 last_file_name != NULL &&
1196 strcmp(filename, last_file_name) != 0)
1197 fh = logfile_open(filename, "w", true);
1199 fh = logfile_open(filename, "a", true);
1204 * ENFILE/EMFILE are not too surprising on a busy system; just
1205 * keep using the old file till we manage to get a new one.
1206 * Otherwise, assume something's wrong with Log_directory and stop
1207 * trying to create files.
1209 if (errno != ENFILE && errno != EMFILE)
1212 (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1213 rotation_disabled = true;
1226 /* instead of pfree'ing filename, remember it for next time */
1227 if (last_file_name != NULL)
1228 pfree(last_file_name);
1229 last_file_name = filename;
1233 /* Same as above, but for csv file. */
1235 if (csvlogFile != NULL &&
1236 (time_based_rotation || (size_rotation_for & LOG_DESTINATION_CSVLOG)))
1238 if (Log_truncate_on_rotation && time_based_rotation &&
1239 last_csv_file_name != NULL &&
1240 strcmp(csvfilename, last_csv_file_name) != 0)
1241 fh = logfile_open(csvfilename, "w", true);
1243 fh = logfile_open(csvfilename, "a", true);
1248 * ENFILE/EMFILE are not too surprising on a busy system; just
1249 * keep using the old file till we manage to get a new one.
1250 * Otherwise, assume something's wrong with Log_directory and stop
1251 * trying to create files.
1253 if (errno != ENFILE && errno != EMFILE)
1256 (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1257 rotation_disabled = true;
1270 /* instead of pfree'ing filename, remember it for next time */
1271 if (last_csv_file_name != NULL)
1272 pfree(last_csv_file_name);
1273 last_csv_file_name = csvfilename;
1282 set_next_rotation_time();
1287 * construct logfile name using timestamp information
1289 * If suffix isn't NULL, append it to the name, replacing any ".log"
1290 * that may be in the pattern.
1292 * Result is palloc'd.
1295 logfile_getname(pg_time_t timestamp, const char *suffix)
1300 filename = palloc(MAXPGPATH);
1302 snprintf(filename, MAXPGPATH, "%s/", Log_directory);
1304 len = strlen(filename);
1306 /* treat Log_filename as a strftime pattern */
1307 pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
1308 pg_localtime(×tamp, log_timezone));
1312 len = strlen(filename);
1313 if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
1315 strlcpy(filename + len, suffix, MAXPGPATH - len);
1322 * Determine the next planned rotation time, and store in next_rotation_time.
1325 set_next_rotation_time(void)
1331 /* nothing to do if time-based rotation is disabled */
1332 if (Log_RotationAge <= 0)
1336 * The requirements here are to choose the next time > now that is a
1337 * "multiple" of the log rotation interval. "Multiple" can be interpreted
1338 * fairly loosely. In this version we align to log_timezone rather than
1341 rotinterval = Log_RotationAge * SECS_PER_MINUTE; /* convert to seconds */
1342 now = (pg_time_t) time(NULL);
1343 tm = pg_localtime(&now, log_timezone);
1344 now += tm->tm_gmtoff;
1345 now -= now % rotinterval;
1347 now -= tm->tm_gmtoff;
1348 next_rotation_time = now;
1351 /* --------------------------------
1352 * signal handler routines
1353 * --------------------------------
1356 /* SIGHUP: set flag to reload config file */
1358 sigHupHandler(SIGNAL_ARGS)
1360 int save_errno = errno;
1363 SetLatch(&sysLoggerLatch);
1368 /* SIGUSR1: set flag to rotate logfile */
1370 sigUsr1Handler(SIGNAL_ARGS)
1372 int save_errno = errno;
1374 rotation_requested = true;
1375 SetLatch(&sysLoggerLatch);