]> granicus.if.org Git - postgresql/blob - src/backend/postmaster/syslogger.c
Also fix rotation of csvlog on Windows.
[postgresql] / src / backend / postmaster / syslogger.c
1 /*-------------------------------------------------------------------------
2  *
3  * syslogger.c
4  *
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.
13  *
14  * Author: Andreas Pflug <pgadmin@pse-consulting.de>
15  *
16  * Copyright (c) 2004-2013, PostgreSQL Global Development Group
17  *
18  *
19  * IDENTIFICATION
20  *        src/backend/postmaster/syslogger.c
21  *
22  *-------------------------------------------------------------------------
23  */
24 #include "postgres.h"
25
26 #include <fcntl.h>
27 #include <limits.h>
28 #include <signal.h>
29 #include <time.h>
30 #include <unistd.h>
31 #include <sys/stat.h>
32 #include <sys/time.h>
33
34 #include "lib/stringinfo.h"
35 #include "libpq/pqsignal.h"
36 #include "miscadmin.h"
37 #include "nodes/pg_list.h"
38 #include "pgtime.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"
48
49 /*
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
52  * instead on Windows.
53  */
54 #ifdef WIN32
55 #define LBF_MODE        _IONBF
56 #else
57 #define LBF_MODE        _IOLBF
58 #endif
59
60 /*
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.
64  */
65 #define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)
66
67
68 /*
69  * GUC parameters.      Logging_collector cannot be changed after postmaster
70  * start, but the rest can change at SIGHUP.
71  */
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;
79
80 /*
81  * Globally visible state (used by elog.c)
82  */
83 bool            am_syslogger = false;
84
85 extern bool redirection_done;
86
87 /*
88  * Private state
89  */
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;
99
100 /*
101  * Buffers for saving partial messages from different backends.
102  *
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.
107  *
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.
110  */
111 typedef struct
112 {
113         int32           pid;                    /* PID of source process */
114         StringInfoData data;            /* accumulated data, as a StringInfo */
115 } save_buffer;
116
117 #define NBUFFER_LISTS 256
118 static List *buffer_lists[NBUFFER_LISTS];
119
120 /* These must be exported for EXEC_BACKEND case ... annoying */
121 #ifndef WIN32
122 int                     syslogPipe[2] = {-1, -1};
123 #else
124 HANDLE          syslogPipe[2] = {0, 0};
125 #endif
126
127 #ifdef WIN32
128 static HANDLE threadHandle = 0;
129 static CRITICAL_SECTION sysloggerSection;
130 #endif
131
132 /*
133  * Flags set by interrupt handlers for later service in the main loop.
134  */
135 static volatile sig_atomic_t got_SIGHUP = false;
136 static volatile sig_atomic_t rotation_requested = false;
137
138
139 /* Local subroutines */
140 #ifdef EXEC_BACKEND
141 static pid_t syslogger_forkexec(void);
142 static void syslogger_parseArgs(int argc, char *argv[]);
143 #endif
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,
149                          bool allow_errors);
150
151 #ifdef WIN32
152 static unsigned int __stdcall pipeThread(void *arg);
153 #endif
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);
159
160
161 /*
162  * Main entry point for syslogger process
163  * argc/argv parameters are valid only in EXEC_BACKEND case.
164  */
165 NON_EXEC_STATIC void
166 SysLoggerMain(int argc, char *argv[])
167 {
168 #ifndef WIN32
169         char            logbuffer[READ_BUF_SIZE];
170         int                     bytes_in_logbuffer = 0;
171 #endif
172         char       *currentLogDir;
173         char       *currentLogFilename;
174         int                     currentLogRotationAge;
175         pg_time_t       now;
176
177         IsUnderPostmaster = true;       /* we are a postmaster subprocess now */
178
179         MyProcPid = getpid();           /* reset MyProcPid */
180
181         MyStartTime = time(NULL);       /* set our start time in case we call elog */
182         now = MyStartTime;
183
184 #ifdef EXEC_BACKEND
185         syslogger_parseArgs(argc, argv);
186 #endif   /* EXEC_BACKEND */
187
188         am_syslogger = true;
189
190         init_ps_display("logger process", "", "", "");
191
192         /*
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.
198          */
199         if (redirection_done)
200         {
201                 int                     fd = open(DEVNULL, O_WRONLY, 0);
202
203                 /*
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.
208                  */
209                 close(fileno(stdout));
210                 close(fileno(stderr));
211                 if (fd != -1)
212                 {
213                         dup2(fd, fileno(stdout));
214                         dup2(fd, fileno(stderr));
215                         close(fd);
216                 }
217         }
218
219         /*
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).
223          */
224 #ifdef WIN32
225         else
226                 _setmode(_fileno(stderr), _O_TEXT);
227 #endif
228
229         /*
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.)
233          */
234 #ifndef WIN32
235         if (syslogPipe[1] >= 0)
236                 close(syslogPipe[1]);
237         syslogPipe[1] = -1;
238 #else
239         if (syslogPipe[1])
240                 CloseHandle(syslogPipe[1]);
241         syslogPipe[1] = 0;
242 #endif
243
244         /*
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.)
249          */
250 #ifdef HAVE_SETSID
251         if (setsid() < 0)
252                 elog(FATAL, "setsid() failed: %m");
253 #endif
254
255         InitializeLatchSupport();               /* needed for latch waits */
256
257         /* Initialize private latch for use by signal handlers */
258         InitLatch(&sysLoggerLatch);
259
260         /*
261          * Properly accept or ignore signals the postmaster might send us
262          *
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
265          * broken backends...
266          */
267
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);
276
277         /*
278          * Reset some signals that are accepted by postmaster but not here
279          */
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);
285
286         PG_SETMASK(&UnBlockSig);
287
288 #ifdef WIN32
289         /* Fire up separate data transfer thread */
290         InitializeCriticalSection(&sysloggerSection);
291         EnterCriticalSection(&sysloggerSection);
292
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");
296 #endif   /* WIN32 */
297
298         /*
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.
302          */
303         last_file_name = logfile_getname(first_syslogger_file_time, NULL);
304
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();
311
312         /* main worker loop */
313         for (;;)
314         {
315                 bool            time_based_rotation = false;
316                 int                     size_rotation_for = 0;
317                 long            cur_timeout;
318                 int                     cur_flags;
319
320 #ifndef WIN32
321                 int                     rc;
322 #endif
323
324                 /* Clear any already-pending wakeups */
325                 ResetLatch(&sysLoggerLatch);
326
327                 /*
328                  * Process any requests or signals received recently.
329                  */
330                 if (got_SIGHUP)
331                 {
332                         got_SIGHUP = false;
333                         ProcessConfigFile(PGC_SIGHUP);
334
335                         /*
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.
339                          */
340                         if (strcmp(Log_directory, currentLogDir) != 0)
341                         {
342                                 pfree(currentLogDir);
343                                 currentLogDir = pstrdup(Log_directory);
344                                 rotation_requested = true;
345
346                                 /*
347                                  * Also, create new directory if not present; ignore errors
348                                  */
349                                 mkdir(Log_directory, S_IRWXU);
350                         }
351                         if (strcmp(Log_filename, currentLogFilename) != 0)
352                         {
353                                 pfree(currentLogFilename);
354                                 currentLogFilename = pstrdup(Log_filename);
355                                 rotation_requested = true;
356                         }
357
358                         /*
359                          * If rotation time parameter changed, reset next rotation time,
360                          * but don't immediately force a rotation.
361                          */
362                         if (currentLogRotationAge != Log_RotationAge)
363                         {
364                                 currentLogRotationAge = Log_RotationAge;
365                                 set_next_rotation_time();
366                         }
367
368                         /*
369                          * If we had a rotation-disabling failure, re-enable rotation
370                          * attempts after SIGHUP, and force one immediately.
371                          */
372                         if (rotation_disabled)
373                         {
374                                 rotation_disabled = false;
375                                 rotation_requested = true;
376                         }
377                 }
378
379                 if (Log_RotationAge > 0 && !rotation_disabled)
380                 {
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;
385                 }
386
387                 if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
388                 {
389                         /* Do a rotation if file is too big */
390                         if (ftell(syslogFile) >= Log_RotationSize * 1024L)
391                         {
392                                 rotation_requested = true;
393                                 size_rotation_for |= LOG_DESTINATION_STDERR;
394                         }
395                         if (csvlogFile != NULL &&
396                                 ftell(csvlogFile) >= Log_RotationSize * 1024L)
397                         {
398                                 rotation_requested = true;
399                                 size_rotation_for |= LOG_DESTINATION_CSVLOG;
400                         }
401                 }
402
403                 if (rotation_requested)
404                 {
405                         /*
406                          * Force rotation when both values are zero. It means the request
407                          * was sent by pg_rotate_logfile.
408                          */
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);
412                 }
413
414                 /*
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.
420                  *
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.
425                  */
426                 if (Log_RotationAge > 0 && !rotation_disabled)
427                 {
428                         pg_time_t       delay;
429
430                         delay = next_rotation_time - now;
431                         if (delay > 0)
432                         {
433                                 if (delay > INT_MAX / 1000)
434                                         delay = INT_MAX / 1000;
435                                 cur_timeout = delay * 1000L;    /* msec */
436                         }
437                         else
438                                 cur_timeout = 0;
439                         cur_flags = WL_TIMEOUT;
440                 }
441                 else
442                 {
443                         cur_timeout = -1L;
444                         cur_flags = 0;
445                 }
446
447                 /*
448                  * Sleep until there's something to do
449                  */
450 #ifndef WIN32
451                 rc = WaitLatchOrSocket(&sysLoggerLatch,
452                                                            WL_LATCH_SET | WL_SOCKET_READABLE | cur_flags,
453                                                            syslogPipe[0],
454                                                            cur_timeout);
455
456                 if (rc & WL_SOCKET_READABLE)
457                 {
458                         int                     bytesRead;
459
460                         bytesRead = read(syslogPipe[0],
461                                                          logbuffer + bytes_in_logbuffer,
462                                                          sizeof(logbuffer) - bytes_in_logbuffer);
463                         if (bytesRead < 0)
464                         {
465                                 if (errno != EINTR)
466                                         ereport(LOG,
467                                                         (errcode_for_socket_access(),
468                                                          errmsg("could not read from logger pipe: %m")));
469                         }
470                         else if (bytesRead > 0)
471                         {
472                                 bytes_in_logbuffer += bytesRead;
473                                 process_pipe_input(logbuffer, &bytes_in_logbuffer);
474                                 continue;
475                         }
476                         else
477                         {
478                                 /*
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.
483                                  */
484                                 pipe_eof_seen = true;
485
486                                 /* if there's any data left then force it out now */
487                                 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
488                         }
489                 }
490 #else                                                   /* WIN32 */
491
492                 /*
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.
496                  *
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.
500                  */
501                 LeaveCriticalSection(&sysloggerSection);
502
503                 (void) WaitLatch(&sysLoggerLatch,
504                                                  WL_LATCH_SET | cur_flags,
505                                                  cur_timeout);
506
507                 EnterCriticalSection(&sysloggerSection);
508 #endif   /* WIN32 */
509
510                 if (pipe_eof_seen)
511                 {
512                         /*
513                          * seeing this message on the real stderr is annoying - so we make
514                          * it DEBUG1 to suppress in normal use.
515                          */
516                         ereport(DEBUG1,
517                                         (errmsg("logger shutting down")));
518
519                         /*
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.
525                          */
526                         proc_exit(0);
527                 }
528         }
529 }
530
531 /*
532  * Postmaster subroutine to start a syslogger subprocess.
533  */
534 int
535 SysLogger_Start(void)
536 {
537         pid_t           sysloggerPid;
538         char       *filename;
539
540         if (!Logging_collector)
541                 return 0;
542
543         /*
544          * If first time through, create the pipe which will receive stderr
545          * output.
546          *
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
549          * into that pipe).
550          *
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.
554          */
555 #ifndef WIN32
556         if (syslogPipe[0] < 0)
557         {
558                 if (pipe(syslogPipe) < 0)
559                         ereport(FATAL,
560                                         (errcode_for_socket_access(),
561                                          (errmsg("could not create pipe for syslog: %m"))));
562         }
563 #else
564         if (!syslogPipe[0])
565         {
566                 SECURITY_ATTRIBUTES sa;
567
568                 memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
569                 sa.nLength = sizeof(SECURITY_ATTRIBUTES);
570                 sa.bInheritHandle = TRUE;
571
572                 if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
573                         ereport(FATAL,
574                                         (errcode_for_file_access(),
575                                          (errmsg("could not create pipe for syslog: %m"))));
576         }
577 #endif
578
579         /*
580          * Create log directory if not present; ignore errors
581          */
582         mkdir(Log_directory, S_IRWXU);
583
584         /*
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.
588          *
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.
595          */
596         first_syslogger_file_time = time(NULL);
597         filename = logfile_getname(first_syslogger_file_time, NULL);
598
599         syslogFile = logfile_open(filename, "a", false);
600
601         pfree(filename);
602
603 #ifdef EXEC_BACKEND
604         switch ((sysloggerPid = syslogger_forkexec()))
605 #else
606         switch ((sysloggerPid = fork_process()))
607 #endif
608         {
609                 case -1:
610                         ereport(LOG,
611                                         (errmsg("could not fork system logger: %m")));
612                         return 0;
613
614 #ifndef EXEC_BACKEND
615                 case 0:
616                         /* in postmaster child ... */
617                         /* Close the postmaster's sockets */
618                         ClosePostmasterPorts(true);
619
620                         /* Lose the postmaster's on-exit routines */
621                         on_exit_reset();
622
623                         /* Drop our connection to postmaster's shared memory, as well */
624                         PGSharedMemoryDetach();
625
626                         /* do the work */
627                         SysLoggerMain(0, NULL);
628                         break;
629 #endif
630
631                 default:
632                         /* success, in postmaster */
633
634                         /* now we redirect stderr, if not done already */
635                         if (!redirection_done)
636                         {
637 #ifndef WIN32
638                                 fflush(stdout);
639                                 if (dup2(syslogPipe[1], fileno(stdout)) < 0)
640                                         ereport(FATAL,
641                                                         (errcode_for_file_access(),
642                                                          errmsg("could not redirect stdout: %m")));
643                                 fflush(stderr);
644                                 if (dup2(syslogPipe[1], fileno(stderr)) < 0)
645                                         ereport(FATAL,
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]);
650                                 syslogPipe[1] = -1;
651 #else
652                                 int                     fd;
653
654                                 /*
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
657                                  * chunking protocol.
658                                  */
659                                 fflush(stderr);
660                                 fd = _open_osfhandle((intptr_t) syslogPipe[1],
661                                                                          _O_APPEND | _O_BINARY);
662                                 if (dup2(fd, _fileno(stderr)) < 0)
663                                         ereport(FATAL,
664                                                         (errcode_for_file_access(),
665                                                          errmsg("could not redirect stderr: %m")));
666                                 close(fd);
667                                 _setmode(_fileno(stderr), _O_BINARY);
668
669                                 /*
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.
673                                  */
674                                 syslogPipe[1] = 0;
675 #endif
676                                 redirection_done = true;
677                         }
678
679                         /* postmaster will never write the file; close it */
680                         fclose(syslogFile);
681                         syslogFile = NULL;
682                         return (int) sysloggerPid;
683         }
684
685         /* we should never reach here */
686         return 0;
687 }
688
689
690 #ifdef EXEC_BACKEND
691
692 /*
693  * syslogger_forkexec() -
694  *
695  * Format up the arglist for, then fork and exec, a syslogger process
696  */
697 static pid_t
698 syslogger_forkexec(void)
699 {
700         char       *av[10];
701         int                     ac = 0;
702         char            filenobuf[32];
703
704         av[ac++] = "postgres";
705         av[ac++] = "--forklog";
706         av[ac++] = NULL;                        /* filled in by postmaster_forkexec */
707
708         /* static variables (those not passed by write_backend_variables) */
709 #ifndef WIN32
710         if (syslogFile != NULL)
711                 snprintf(filenobuf, sizeof(filenobuf), "%d",
712                                  fileno(syslogFile));
713         else
714                 strcpy(filenobuf, "-1");
715 #else                                                   /* WIN32 */
716         if (syslogFile != NULL)
717                 snprintf(filenobuf, sizeof(filenobuf), "%ld",
718                                  (long) _get_osfhandle(_fileno(syslogFile)));
719         else
720                 strcpy(filenobuf, "0");
721 #endif   /* WIN32 */
722         av[ac++] = filenobuf;
723
724         av[ac] = NULL;
725         Assert(ac < lengthof(av));
726
727         return postmaster_forkexec(ac, av);
728 }
729
730 /*
731  * syslogger_parseArgs() -
732  *
733  * Extract data from the arglist for exec'ed syslogger process
734  */
735 static void
736 syslogger_parseArgs(int argc, char *argv[])
737 {
738         int                     fd;
739
740         Assert(argc == 4);
741         argv += 3;
742
743 #ifndef WIN32
744         fd = atoi(*argv++);
745         if (fd != -1)
746         {
747                 syslogFile = fdopen(fd, "a");
748                 setvbuf(syslogFile, NULL, LBF_MODE, 0);
749         }
750 #else                                                   /* WIN32 */
751         fd = atoi(*argv++);
752         if (fd != 0)
753         {
754                 fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
755                 if (fd > 0)
756                 {
757                         syslogFile = fdopen(fd, "a");
758                         setvbuf(syslogFile, NULL, LBF_MODE, 0);
759                 }
760         }
761 #endif   /* WIN32 */
762 }
763 #endif   /* EXEC_BACKEND */
764
765
766 /* --------------------------------
767  *              pipe protocol handling
768  * --------------------------------
769  */
770
771 /*
772  * Process data received through the syslogger pipe.
773  *
774  * This routine interprets the log pipe protocol which sends log messages as
775  * (hopefully atomic) chunks - such chunks are detected and reassembled here.
776  *
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.
781  *
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).
785  *
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
788  * stderr).
789  *
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.
793  */
794 static void
795 process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
796 {
797         char       *cursor = logbuffer;
798         int                     count = *bytes_in_logbuffer;
799         int                     dest = LOG_DESTINATION_STDERR;
800
801         /* While we have enough for a header, process data... */
802         while (count >= (int) sizeof(PipeProtoHeader))
803         {
804                 PipeProtoHeader p;
805                 int                     chunklen;
806
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 &&
811                         p.pid != 0 &&
812                         (p.is_last == 't' || p.is_last == 'f' ||
813                          p.is_last == 'T' || p.is_last == 'F'))
814                 {
815                         List       *buffer_list;
816                         ListCell   *cell;
817                         save_buffer *existing_slot = NULL,
818                                            *free_slot = NULL;
819                         StringInfo      str;
820
821                         chunklen = PIPE_HEADER_SIZE + p.len;
822
823                         /* Fall out of loop if we don't have the whole chunk yet */
824                         if (count < chunklen)
825                                 break;
826
827                         dest = (p.is_last == 'T' || p.is_last == 'F') ?
828                                 LOG_DESTINATION_CSVLOG : LOG_DESTINATION_STDERR;
829
830                         /* Locate any existing buffer for this source pid */
831                         buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
832                         foreach(cell, buffer_list)
833                         {
834                                 save_buffer *buf = (save_buffer *) lfirst(cell);
835
836                                 if (buf->pid == p.pid)
837                                 {
838                                         existing_slot = buf;
839                                         break;
840                                 }
841                                 if (buf->pid == 0 && free_slot == NULL)
842                                         free_slot = buf;
843                         }
844
845                         if (p.is_last == 'f' || p.is_last == 'F')
846                         {
847                                 /*
848                                  * Save a complete non-final chunk in a per-pid buffer
849                                  */
850                                 if (existing_slot != NULL)
851                                 {
852                                         /* Add chunk to data from preceding chunks */
853                                         str = &(existing_slot->data);
854                                         appendBinaryStringInfo(str,
855                                                                                    cursor + PIPE_HEADER_SIZE,
856                                                                                    p.len);
857                                 }
858                                 else
859                                 {
860                                         /* First chunk of message, save in a new buffer */
861                                         if (free_slot == NULL)
862                                         {
863                                                 /*
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.
866                                                  */
867                                                 free_slot = palloc(sizeof(save_buffer));
868                                                 buffer_list = lappend(buffer_list, free_slot);
869                                                 buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
870                                         }
871                                         free_slot->pid = p.pid;
872                                         str = &(free_slot->data);
873                                         initStringInfo(str);
874                                         appendBinaryStringInfo(str,
875                                                                                    cursor + PIPE_HEADER_SIZE,
876                                                                                    p.len);
877                                 }
878                         }
879                         else
880                         {
881                                 /*
882                                  * Final chunk --- add it to anything saved for that pid, and
883                                  * either way write the whole thing out.
884                                  */
885                                 if (existing_slot != NULL)
886                                 {
887                                         str = &(existing_slot->data);
888                                         appendBinaryStringInfo(str,
889                                                                                    cursor + PIPE_HEADER_SIZE,
890                                                                                    p.len);
891                                         write_syslogger_file(str->data, str->len, dest);
892                                         /* Mark the buffer unused, and reclaim string storage */
893                                         existing_slot->pid = 0;
894                                         pfree(str->data);
895                                 }
896                                 else
897                                 {
898                                         /* The whole message was one chunk, evidently. */
899                                         write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
900                                                                                  dest);
901                                 }
902                         }
903
904                         /* Finished processing this chunk */
905                         cursor += chunklen;
906                         count -= chunklen;
907                 }
908                 else
909                 {
910                         /* Process non-protocol data */
911
912                         /*
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.)
920                          */
921                         for (chunklen = 1; chunklen < count; chunklen++)
922                         {
923                                 if (cursor[chunklen] == '\0')
924                                         break;
925                         }
926                         /* fall back on the stderr log as the destination */
927                         write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
928                         cursor += chunklen;
929                         count -= chunklen;
930                 }
931         }
932
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;
937 }
938
939 /*
940  * Force out any buffered data
941  *
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.
944  */
945 static void
946 flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
947 {
948         int                     i;
949
950         /* Dump any incomplete protocol messages */
951         for (i = 0; i < NBUFFER_LISTS; i++)
952         {
953                 List       *list = buffer_lists[i];
954                 ListCell   *cell;
955
956                 foreach(cell, list)
957                 {
958                         save_buffer *buf = (save_buffer *) lfirst(cell);
959
960                         if (buf->pid != 0)
961                         {
962                                 StringInfo      str = &(buf->data);
963
964                                 write_syslogger_file(str->data, str->len,
965                                                                          LOG_DESTINATION_STDERR);
966                                 /* Mark the buffer unused, and reclaim string storage */
967                                 buf->pid = 0;
968                                 pfree(str->data);
969                         }
970                 }
971         }
972
973         /*
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.
976          */
977         if (*bytes_in_logbuffer > 0)
978                 write_syslogger_file(logbuffer, *bytes_in_logbuffer,
979                                                          LOG_DESTINATION_STDERR);
980         *bytes_in_logbuffer = 0;
981 }
982
983
984 /* --------------------------------
985  *              logfile routines
986  * --------------------------------
987  */
988
989 /*
990  * Write text to the currently open logfile
991  *
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.
995  */
996 void
997 write_syslogger_file(const char *buffer, int count, int destination)
998 {
999         int                     rc;
1000         FILE       *logfile;
1001
1002         if (destination == LOG_DESTINATION_CSVLOG && csvlogFile == NULL)
1003                 open_csvlogfile();
1004
1005         logfile = destination == LOG_DESTINATION_CSVLOG ? csvlogFile : syslogFile;
1006         rc = fwrite(buffer, 1, count, logfile);
1007
1008         /* can't use ereport here because of possible recursion */
1009         if (rc != count)
1010                 write_stderr("could not write to log file: %s\n", strerror(errno));
1011 }
1012
1013 #ifdef WIN32
1014
1015 /*
1016  * Worker thread to transfer data from the pipe to the current logfile.
1017  *
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.
1021  */
1022 static unsigned int __stdcall
1023 pipeThread(void *arg)
1024 {
1025         char            logbuffer[READ_BUF_SIZE];
1026         int                     bytes_in_logbuffer = 0;
1027
1028         for (;;)
1029         {
1030                 DWORD           bytesRead;
1031                 BOOL            result;
1032
1033                 result = ReadFile(syslogPipe[0],
1034                                                   logbuffer + bytes_in_logbuffer,
1035                                                   sizeof(logbuffer) - bytes_in_logbuffer,
1036                                                   &bytesRead, 0);
1037
1038                 /*
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
1042                  * section.
1043                  */
1044                 EnterCriticalSection(&sysloggerSection);
1045                 if (!result)
1046                 {
1047                         DWORD           error = GetLastError();
1048
1049                         if (error == ERROR_HANDLE_EOF ||
1050                                 error == ERROR_BROKEN_PIPE)
1051                                 break;
1052                         _dosmaperr(error);
1053                         ereport(LOG,
1054                                         (errcode_for_file_access(),
1055                                          errmsg("could not read from logger pipe: %m")));
1056                 }
1057                 else if (bytesRead > 0)
1058                 {
1059                         bytes_in_logbuffer += bytesRead;
1060                         process_pipe_input(logbuffer, &bytes_in_logbuffer);
1061                 }
1062
1063                 /*
1064                  * If we've filled the current logfile, nudge the main thread to do a
1065                  * log rotation.
1066                  */
1067                 if (Log_RotationSize > 0)
1068                 {
1069                         if (ftell(syslogFile) >= Log_RotationSize * 1024L ||
1070                                 (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L))
1071                                 SetLatch(&sysLoggerLatch);
1072                 }
1073                 LeaveCriticalSection(&sysloggerSection);
1074         }
1075
1076         /* We exit the above loop only upon detecting pipe EOF */
1077         pipe_eof_seen = true;
1078
1079         /* if there's any data left then force it out now */
1080         flush_pipe_input(logbuffer, &bytes_in_logbuffer);
1081
1082         /* set the latch to waken the main thread, which will quit */
1083         SetLatch(&sysLoggerLatch);
1084
1085         LeaveCriticalSection(&sysloggerSection);
1086         _endthread();
1087         return 0;
1088 }
1089 #endif   /* WIN32 */
1090
1091 /*
1092  * Open the csv log file - we do this opportunistically, because
1093  * we don't know if CSV logging will be wanted.
1094  *
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.
1098  */
1099 static void
1100 open_csvlogfile(void)
1101 {
1102         char       *filename;
1103
1104         filename = logfile_getname(time(NULL), ".csv");
1105
1106         csvlogFile = logfile_open(filename, "a", false);
1107
1108         if (last_csv_file_name != NULL)         /* probably shouldn't happen */
1109                 pfree(last_csv_file_name);
1110
1111         last_csv_file_name = filename;
1112 }
1113
1114 /*
1115  * Open a new logfile with proper permissions and buffering options.
1116  *
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.
1120  */
1121 static FILE *
1122 logfile_open(const char *filename, const char *mode, bool allow_errors)
1123 {
1124         FILE       *fh;
1125         mode_t          oumask;
1126
1127         /*
1128          * Note we do not let Log_file_mode disable IWUSR, since we certainly want
1129          * to be able to write the files ourselves.
1130          */
1131         oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
1132         fh = fopen(filename, mode);
1133         umask(oumask);
1134
1135         if (fh)
1136         {
1137                 setvbuf(fh, NULL, LBF_MODE, 0);
1138
1139 #ifdef WIN32
1140                 /* use CRLF line endings on Windows */
1141                 _setmode(_fileno(fh), _O_TEXT);
1142 #endif
1143         }
1144         else
1145         {
1146                 int                     save_errno = errno;
1147
1148                 ereport(allow_errors ? LOG : FATAL,
1149                                 (errcode_for_file_access(),
1150                                  errmsg("could not open log file \"%s\": %m",
1151                                                 filename)));
1152                 errno = save_errno;
1153         }
1154
1155         return fh;
1156 }
1157
1158 /*
1159  * perform logfile rotation
1160  */
1161 static void
1162 logfile_rotate(bool time_based_rotation, int size_rotation_for)
1163 {
1164         char       *filename;
1165         char       *csvfilename = NULL;
1166         pg_time_t       fntime;
1167         FILE       *fh;
1168
1169         rotation_requested = false;
1170
1171         /*
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.
1175          */
1176         if (time_based_rotation)
1177                 fntime = next_rotation_time;
1178         else
1179                 fntime = time(NULL);
1180         filename = logfile_getname(fntime, NULL);
1181         if (csvlogFile != NULL)
1182                 csvfilename = logfile_getname(fntime, ".csv");
1183
1184         /*
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.
1189          *
1190          * Note: last_file_name should never be NULL here, but if it is, append.
1191          */
1192         if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
1193         {
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);
1198                 else
1199                         fh = logfile_open(filename, "a", true);
1200
1201                 if (!fh)
1202                 {
1203                         /*
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.
1208                          */
1209                         if (errno != ENFILE && errno != EMFILE)
1210                         {
1211                                 ereport(LOG,
1212                                                 (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1213                                 rotation_disabled = true;
1214                         }
1215
1216                         if (filename)
1217                                 pfree(filename);
1218                         if (csvfilename)
1219                                 pfree(csvfilename);
1220                         return;
1221                 }
1222
1223                 fclose(syslogFile);
1224                 syslogFile = fh;
1225
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;
1230                 filename = NULL;
1231         }
1232
1233         /* Same as above, but for csv file. */
1234
1235         if (csvlogFile != NULL &&
1236                 (time_based_rotation || (size_rotation_for & LOG_DESTINATION_CSVLOG)))
1237         {
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);
1242                 else
1243                         fh = logfile_open(csvfilename, "a", true);
1244
1245                 if (!fh)
1246                 {
1247                         /*
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.
1252                          */
1253                         if (errno != ENFILE && errno != EMFILE)
1254                         {
1255                                 ereport(LOG,
1256                                                 (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1257                                 rotation_disabled = true;
1258                         }
1259
1260                         if (filename)
1261                                 pfree(filename);
1262                         if (csvfilename)
1263                                 pfree(csvfilename);
1264                         return;
1265                 }
1266
1267                 fclose(csvlogFile);
1268                 csvlogFile = fh;
1269
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;
1274                 csvfilename = NULL;
1275         }
1276
1277         if (filename)
1278                 pfree(filename);
1279         if (csvfilename)
1280                 pfree(csvfilename);
1281
1282         set_next_rotation_time();
1283 }
1284
1285
1286 /*
1287  * construct logfile name using timestamp information
1288  *
1289  * If suffix isn't NULL, append it to the name, replacing any ".log"
1290  * that may be in the pattern.
1291  *
1292  * Result is palloc'd.
1293  */
1294 static char *
1295 logfile_getname(pg_time_t timestamp, const char *suffix)
1296 {
1297         char       *filename;
1298         int                     len;
1299
1300         filename = palloc(MAXPGPATH);
1301
1302         snprintf(filename, MAXPGPATH, "%s/", Log_directory);
1303
1304         len = strlen(filename);
1305
1306         /* treat Log_filename as a strftime pattern */
1307         pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
1308                                 pg_localtime(&timestamp, log_timezone));
1309
1310         if (suffix != NULL)
1311         {
1312                 len = strlen(filename);
1313                 if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
1314                         len -= 4;
1315                 strlcpy(filename + len, suffix, MAXPGPATH - len);
1316         }
1317
1318         return filename;
1319 }
1320
1321 /*
1322  * Determine the next planned rotation time, and store in next_rotation_time.
1323  */
1324 static void
1325 set_next_rotation_time(void)
1326 {
1327         pg_time_t       now;
1328         struct pg_tm *tm;
1329         int                     rotinterval;
1330
1331         /* nothing to do if time-based rotation is disabled */
1332         if (Log_RotationAge <= 0)
1333                 return;
1334
1335         /*
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
1339          * GMT.
1340          */
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;
1346         now += rotinterval;
1347         now -= tm->tm_gmtoff;
1348         next_rotation_time = now;
1349 }
1350
1351 /* --------------------------------
1352  *              signal handler routines
1353  * --------------------------------
1354  */
1355
1356 /* SIGHUP: set flag to reload config file */
1357 static void
1358 sigHupHandler(SIGNAL_ARGS)
1359 {
1360         int                     save_errno = errno;
1361
1362         got_SIGHUP = true;
1363         SetLatch(&sysLoggerLatch);
1364
1365         errno = save_errno;
1366 }
1367
1368 /* SIGUSR1: set flag to rotate logfile */
1369 static void
1370 sigUsr1Handler(SIGNAL_ARGS)
1371 {
1372         int                     save_errno = errno;
1373
1374         rotation_requested = true;
1375         SetLatch(&sysLoggerLatch);
1376
1377         errno = save_errno;
1378 }