LCOV - code coverage report
Current view: top level - src/backend/postmaster - syslogger.c (source / functions) Hit Total Coverage
Test: PostgreSQL 13beta1 Lines: 209 376 55.6 %
Date: 2020-06-01 09:07:10 Functions: 13 14 92.9 %
Legend: Lines: hit not hit

          Line data    Source code
       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-2020, 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 "common/file_perm.h"
      35             : #include "lib/stringinfo.h"
      36             : #include "libpq/pqsignal.h"
      37             : #include "miscadmin.h"
      38             : #include "nodes/pg_list.h"
      39             : #include "pgstat.h"
      40             : #include "pgtime.h"
      41             : #include "postmaster/fork_process.h"
      42             : #include "postmaster/postmaster.h"
      43             : #include "postmaster/syslogger.h"
      44             : #include "storage/dsm.h"
      45             : #include "storage/fd.h"
      46             : #include "storage/ipc.h"
      47             : #include "storage/latch.h"
      48             : #include "storage/pg_shmem.h"
      49             : #include "tcop/tcopprot.h"
      50             : #include "utils/guc.h"
      51             : #include "utils/ps_status.h"
      52             : #include "utils/timestamp.h"
      53             : 
      54             : /*
      55             :  * We read() into a temp buffer twice as big as a chunk, so that any fragment
      56             :  * left after processing can be moved down to the front and we'll still have
      57             :  * room to read a full chunk.
      58             :  */
      59             : #define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)
      60             : 
      61             : /* Log rotation signal file path, relative to $PGDATA */
      62             : #define LOGROTATE_SIGNAL_FILE   "logrotate"
      63             : 
      64             : 
      65             : /*
      66             :  * GUC parameters.  Logging_collector cannot be changed after postmaster
      67             :  * start, but the rest can change at SIGHUP.
      68             :  */
      69             : bool        Logging_collector = false;
      70             : int         Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
      71             : int         Log_RotationSize = 10 * 1024;
      72             : char       *Log_directory = NULL;
      73             : char       *Log_filename = NULL;
      74             : bool        Log_truncate_on_rotation = false;
      75             : int         Log_file_mode = S_IRUSR | S_IWUSR;
      76             : 
      77             : extern bool redirection_done;
      78             : 
      79             : /*
      80             :  * Private state
      81             :  */
      82             : static pg_time_t next_rotation_time;
      83             : static bool pipe_eof_seen = false;
      84             : static bool rotation_disabled = false;
      85             : static FILE *syslogFile = NULL;
      86             : static FILE *csvlogFile = NULL;
      87             : NON_EXEC_STATIC pg_time_t first_syslogger_file_time = 0;
      88             : static char *last_file_name = NULL;
      89             : static char *last_csv_file_name = NULL;
      90             : 
      91             : /*
      92             :  * Buffers for saving partial messages from different backends.
      93             :  *
      94             :  * Keep NBUFFER_LISTS lists of these, with the entry for a given source pid
      95             :  * being in the list numbered (pid % NBUFFER_LISTS), so as to cut down on
      96             :  * the number of entries we have to examine for any one incoming message.
      97             :  * There must never be more than one entry for the same source pid.
      98             :  *
      99             :  * An inactive buffer is not removed from its list, just held for re-use.
     100             :  * An inactive buffer has pid == 0 and undefined contents of data.
     101             :  */
     102             : typedef struct
     103             : {
     104             :     int32       pid;            /* PID of source process */
     105             :     StringInfoData data;        /* accumulated data, as a StringInfo */
     106             : } save_buffer;
     107             : 
     108             : #define NBUFFER_LISTS 256
     109             : static List *buffer_lists[NBUFFER_LISTS];
     110             : 
     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
     117             : 
     118             : #ifdef WIN32
     119             : static HANDLE threadHandle = 0;
     120             : static CRITICAL_SECTION sysloggerSection;
     121             : #endif
     122             : 
     123             : /*
     124             :  * Flags set by interrupt handlers for later service in the main loop.
     125             :  */
     126             : static volatile sig_atomic_t got_SIGHUP = false;
     127             : static volatile sig_atomic_t rotation_requested = false;
     128             : 
     129             : 
     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             : NON_EXEC_STATIC void SysLoggerMain(int argc, char *argv[]) pg_attribute_noreturn();
     136             : static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
     137             : static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
     138             : static FILE *logfile_open(const char *filename, const char *mode,
     139             :                           bool allow_errors);
     140             : 
     141             : #ifdef WIN32
     142             : static unsigned int __stdcall pipeThread(void *arg);
     143             : #endif
     144             : static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
     145             : static char *logfile_getname(pg_time_t timestamp, const char *suffix);
     146             : static void set_next_rotation_time(void);
     147             : static void sigHupHandler(SIGNAL_ARGS);
     148             : static void sigUsr1Handler(SIGNAL_ARGS);
     149             : static void update_metainfo_datafile(void);
     150             : 
     151             : 
     152             : /*
     153             :  * Main entry point for syslogger process
     154             :  * argc/argv parameters are valid only in EXEC_BACKEND case.
     155             :  */
     156             : NON_EXEC_STATIC void
     157           2 : SysLoggerMain(int argc, char *argv[])
     158             : {
     159             : #ifndef WIN32
     160             :     char        logbuffer[READ_BUF_SIZE];
     161           2 :     int         bytes_in_logbuffer = 0;
     162             : #endif
     163             :     char       *currentLogDir;
     164             :     char       *currentLogFilename;
     165             :     int         currentLogRotationAge;
     166             :     pg_time_t   now;
     167             :     WaitEventSet *wes;
     168             : 
     169           2 :     now = MyStartTime;
     170             : 
     171             : #ifdef EXEC_BACKEND
     172             :     syslogger_parseArgs(argc, argv);
     173             : #endif                          /* EXEC_BACKEND */
     174             : 
     175           2 :     MyBackendType = B_LOGGER;
     176           2 :     init_ps_display(NULL);
     177             : 
     178             :     /*
     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.
     184             :      */
     185           2 :     if (redirection_done)
     186             :     {
     187           0 :         int         fd = open(DEVNULL, O_WRONLY, 0);
     188             : 
     189             :         /*
     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.
     194             :          *
     195             :          * As we're just trying to reset these to go to DEVNULL, there's not
     196             :          * much point in checking for failure from the close/dup2 calls here,
     197             :          * if they fail then presumably the file descriptors are closed and
     198             :          * any writes will go into the bitbucket anyway.
     199             :          */
     200           0 :         close(fileno(stdout));
     201           0 :         close(fileno(stderr));
     202           0 :         if (fd != -1)
     203             :         {
     204           0 :             (void) dup2(fd, fileno(stdout));
     205           0 :             (void) dup2(fd, fileno(stderr));
     206           0 :             close(fd);
     207             :         }
     208             :     }
     209             : 
     210             :     /*
     211             :      * Syslogger's own stderr can't be the syslogPipe, so set it back to text
     212             :      * mode if we didn't just close it. (It was set to binary in
     213             :      * SubPostmasterMain).
     214             :      */
     215             : #ifdef WIN32
     216             :     else
     217             :         _setmode(_fileno(stderr), _O_TEXT);
     218             : #endif
     219             : 
     220             :     /*
     221             :      * Also close our copy of the write end of the pipe.  This is needed to
     222             :      * ensure we can detect pipe EOF correctly.  (But note that in the restart
     223             :      * case, the postmaster already did this.)
     224             :      */
     225             : #ifndef WIN32
     226           2 :     if (syslogPipe[1] >= 0)
     227           2 :         close(syslogPipe[1]);
     228           2 :     syslogPipe[1] = -1;
     229             : #else
     230             :     if (syslogPipe[1])
     231             :         CloseHandle(syslogPipe[1]);
     232             :     syslogPipe[1] = 0;
     233             : #endif
     234             : 
     235             :     /*
     236             :      * Properly accept or ignore signals the postmaster might send us
     237             :      *
     238             :      * Note: we ignore all termination signals, and instead exit only when all
     239             :      * upstream processes are gone, to ensure we don't miss any dying gasps of
     240             :      * broken backends...
     241             :      */
     242             : 
     243           2 :     pqsignal(SIGHUP, sigHupHandler);    /* set flag to read config file */
     244           2 :     pqsignal(SIGINT, SIG_IGN);
     245           2 :     pqsignal(SIGTERM, SIG_IGN);
     246           2 :     pqsignal(SIGQUIT, SIG_IGN);
     247           2 :     pqsignal(SIGALRM, SIG_IGN);
     248           2 :     pqsignal(SIGPIPE, SIG_IGN);
     249           2 :     pqsignal(SIGUSR1, sigUsr1Handler);  /* request log rotation */
     250           2 :     pqsignal(SIGUSR2, SIG_IGN);
     251             : 
     252             :     /*
     253             :      * Reset some signals that are accepted by postmaster but not here
     254             :      */
     255           2 :     pqsignal(SIGCHLD, SIG_DFL);
     256             : 
     257           2 :     PG_SETMASK(&UnBlockSig);
     258             : 
     259             : #ifdef WIN32
     260             :     /* Fire up separate data transfer thread */
     261             :     InitializeCriticalSection(&sysloggerSection);
     262             :     EnterCriticalSection(&sysloggerSection);
     263             : 
     264             :     threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
     265             :     if (threadHandle == 0)
     266             :         elog(FATAL, "could not create syslogger data transfer thread: %m");
     267             : #endif                          /* WIN32 */
     268             : 
     269             :     /*
     270             :      * Remember active logfiles' name(s).  We recompute 'em from the reference
     271             :      * time because passing down just the pg_time_t is a lot cheaper than
     272             :      * passing a whole file path in the EXEC_BACKEND case.
     273             :      */
     274           2 :     last_file_name = logfile_getname(first_syslogger_file_time, NULL);
     275           2 :     if (csvlogFile != NULL)
     276           0 :         last_csv_file_name = logfile_getname(first_syslogger_file_time, ".csv");
     277             : 
     278             :     /* remember active logfile parameters */
     279           2 :     currentLogDir = pstrdup(Log_directory);
     280           2 :     currentLogFilename = pstrdup(Log_filename);
     281           2 :     currentLogRotationAge = Log_RotationAge;
     282             :     /* set next planned rotation time */
     283           2 :     set_next_rotation_time();
     284           2 :     update_metainfo_datafile();
     285             : 
     286             :     /*
     287             :      * Reset whereToSendOutput, as the postmaster will do (but hasn't yet, at
     288             :      * the point where we forked).  This prevents duplicate output of messages
     289             :      * from syslogger itself.
     290             :      */
     291           2 :     whereToSendOutput = DestNone;
     292             : 
     293             :     /*
     294             :      * Set up a reusable WaitEventSet object we'll use to wait for our latch,
     295             :      * and (except on Windows) our socket.
     296             :      *
     297             :      * Unlike all other postmaster child processes, we'll ignore postmaster
     298             :      * death because we want to collect final log output from all backends and
     299             :      * then exit last.  We'll do that by running until we see EOF on the
     300             :      * syslog pipe, which implies that all other backends have exited
     301             :      * (including the postmaster).
     302             :      */
     303           2 :     wes = CreateWaitEventSet(CurrentMemoryContext, 2);
     304           2 :     AddWaitEventToSet(wes, WL_LATCH_SET, PGINVALID_SOCKET, MyLatch, NULL);
     305             : #ifndef WIN32
     306           2 :     AddWaitEventToSet(wes, WL_SOCKET_READABLE, syslogPipe[0], NULL, NULL);
     307             : #endif
     308             : 
     309             :     /* main worker loop */
     310             :     for (;;)
     311          24 :     {
     312          26 :         bool        time_based_rotation = false;
     313          26 :         int         size_rotation_for = 0;
     314             :         long        cur_timeout;
     315             :         WaitEvent   event;
     316             : 
     317             : #ifndef WIN32
     318             :         int         rc;
     319             : #endif
     320             : 
     321             :         /* Clear any already-pending wakeups */
     322          26 :         ResetLatch(MyLatch);
     323             : 
     324             :         /*
     325             :          * Process any requests or signals received recently.
     326             :          */
     327          26 :         if (got_SIGHUP)
     328             :         {
     329           0 :             got_SIGHUP = false;
     330           0 :             ProcessConfigFile(PGC_SIGHUP);
     331             : 
     332             :             /*
     333             :              * Check if the log directory or filename pattern changed in
     334             :              * postgresql.conf. If so, force rotation to make sure we're
     335             :              * writing the logfiles in the right place.
     336             :              */
     337           0 :             if (strcmp(Log_directory, currentLogDir) != 0)
     338             :             {
     339           0 :                 pfree(currentLogDir);
     340           0 :                 currentLogDir = pstrdup(Log_directory);
     341           0 :                 rotation_requested = true;
     342             : 
     343             :                 /*
     344             :                  * Also, create new directory if not present; ignore errors
     345             :                  */
     346           0 :                 (void) MakePGDirectory(Log_directory);
     347             :             }
     348           0 :             if (strcmp(Log_filename, currentLogFilename) != 0)
     349             :             {
     350           0 :                 pfree(currentLogFilename);
     351           0 :                 currentLogFilename = pstrdup(Log_filename);
     352           0 :                 rotation_requested = true;
     353             :             }
     354             : 
     355             :             /*
     356             :              * Force a rotation if CSVLOG output was just turned on or off and
     357             :              * we need to open or close csvlogFile accordingly.
     358             :              */
     359           0 :             if (((Log_destination & LOG_DESTINATION_CSVLOG) != 0) !=
     360             :                 (csvlogFile != NULL))
     361           0 :                 rotation_requested = true;
     362             : 
     363             :             /*
     364             :              * If rotation time parameter changed, reset next rotation time,
     365             :              * but don't immediately force a rotation.
     366             :              */
     367           0 :             if (currentLogRotationAge != Log_RotationAge)
     368             :             {
     369           0 :                 currentLogRotationAge = Log_RotationAge;
     370           0 :                 set_next_rotation_time();
     371             :             }
     372             : 
     373             :             /*
     374             :              * If we had a rotation-disabling failure, re-enable rotation
     375             :              * attempts after SIGHUP, and force one immediately.
     376             :              */
     377           0 :             if (rotation_disabled)
     378             :             {
     379           0 :                 rotation_disabled = false;
     380           0 :                 rotation_requested = true;
     381             :             }
     382             : 
     383             :             /*
     384             :              * Force rewriting last log filename when reloading configuration.
     385             :              * Even if rotation_requested is false, log_destination may have
     386             :              * been changed and we don't want to wait the next file rotation.
     387             :              */
     388           0 :             update_metainfo_datafile();
     389             :         }
     390             : 
     391          26 :         if (Log_RotationAge > 0 && !rotation_disabled)
     392             :         {
     393             :             /* Do a logfile rotation if it's time */
     394          26 :             now = (pg_time_t) time(NULL);
     395          26 :             if (now >= next_rotation_time)
     396           0 :                 rotation_requested = time_based_rotation = true;
     397             :         }
     398             : 
     399          26 :         if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
     400             :         {
     401             :             /* Do a rotation if file is too big */
     402          24 :             if (ftell(syslogFile) >= Log_RotationSize * 1024L)
     403             :             {
     404           0 :                 rotation_requested = true;
     405           0 :                 size_rotation_for |= LOG_DESTINATION_STDERR;
     406             :             }
     407          24 :             if (csvlogFile != NULL &&
     408           0 :                 ftell(csvlogFile) >= Log_RotationSize * 1024L)
     409             :             {
     410           0 :                 rotation_requested = true;
     411           0 :                 size_rotation_for |= LOG_DESTINATION_CSVLOG;
     412             :             }
     413             :         }
     414             : 
     415          26 :         if (rotation_requested)
     416             :         {
     417             :             /*
     418             :              * Force rotation when both values are zero. It means the request
     419             :              * was sent by pg_rotate_logfile() or "pg_ctl logrotate".
     420             :              */
     421           2 :             if (!time_based_rotation && size_rotation_for == 0)
     422           2 :                 size_rotation_for = LOG_DESTINATION_STDERR | LOG_DESTINATION_CSVLOG;
     423           2 :             logfile_rotate(time_based_rotation, size_rotation_for);
     424             :         }
     425             : 
     426             :         /*
     427             :          * Calculate time till next time-based rotation, so that we don't
     428             :          * sleep longer than that.  We assume the value of "now" obtained
     429             :          * above is still close enough.  Note we can't make this calculation
     430             :          * until after calling logfile_rotate(), since it will advance
     431             :          * next_rotation_time.
     432             :          *
     433             :          * Also note that we need to beware of overflow in calculation of the
     434             :          * timeout: with large settings of Log_RotationAge, next_rotation_time
     435             :          * could be more than INT_MAX msec in the future.  In that case we'll
     436             :          * wait no more than INT_MAX msec, and try again.
     437             :          */
     438          26 :         if (Log_RotationAge > 0 && !rotation_disabled)
     439          26 :         {
     440             :             pg_time_t   delay;
     441             : 
     442          26 :             delay = next_rotation_time - now;
     443          26 :             if (delay > 0)
     444             :             {
     445          26 :                 if (delay > INT_MAX / 1000)
     446           0 :                     delay = INT_MAX / 1000;
     447          26 :                 cur_timeout = delay * 1000L;    /* msec */
     448             :             }
     449             :             else
     450           0 :                 cur_timeout = 0;
     451             :         }
     452             :         else
     453           0 :             cur_timeout = -1L;
     454             : 
     455             :         /*
     456             :          * Sleep until there's something to do
     457             :          */
     458             : #ifndef WIN32
     459          26 :         rc = WaitEventSetWait(wes, cur_timeout, &event, 1,
     460             :                               WAIT_EVENT_SYSLOGGER_MAIN);
     461             : 
     462          26 :         if (rc == 1 && event.events == WL_SOCKET_READABLE)
     463             :         {
     464             :             int         bytesRead;
     465             : 
     466          24 :             bytesRead = read(syslogPipe[0],
     467             :                              logbuffer + bytes_in_logbuffer,
     468             :                              sizeof(logbuffer) - bytes_in_logbuffer);
     469          24 :             if (bytesRead < 0)
     470             :             {
     471           0 :                 if (errno != EINTR)
     472           0 :                     ereport(LOG,
     473             :                             (errcode_for_socket_access(),
     474             :                              errmsg("could not read from logger pipe: %m")));
     475             :             }
     476          24 :             else if (bytesRead > 0)
     477             :             {
     478          22 :                 bytes_in_logbuffer += bytesRead;
     479          22 :                 process_pipe_input(logbuffer, &bytes_in_logbuffer);
     480          22 :                 continue;
     481             :             }
     482             :             else
     483             :             {
     484             :                 /*
     485             :                  * Zero bytes read when select() is saying read-ready means
     486             :                  * EOF on the pipe: that is, there are no longer any processes
     487             :                  * with the pipe write end open.  Therefore, the postmaster
     488             :                  * and all backends are shut down, and we are done.
     489             :                  */
     490           2 :                 pipe_eof_seen = true;
     491             : 
     492             :                 /* if there's any data left then force it out now */
     493           2 :                 flush_pipe_input(logbuffer, &bytes_in_logbuffer);
     494             :             }
     495             :         }
     496             : #else                           /* WIN32 */
     497             : 
     498             :         /*
     499             :          * On Windows we leave it to a separate thread to transfer data and
     500             :          * detect pipe EOF.  The main thread just wakes up to handle SIGHUP
     501             :          * and rotation conditions.
     502             :          *
     503             :          * Server code isn't generally thread-safe, so we ensure that only one
     504             :          * of the threads is active at a time by entering the critical section
     505             :          * whenever we're not sleeping.
     506             :          */
     507             :         LeaveCriticalSection(&sysloggerSection);
     508             : 
     509             :         (void) WaitEventSetWait(wes, cur_timeout, &event, 1,
     510             :                                 WAIT_EVENT_SYSLOGGER_MAIN);
     511             : 
     512             :         EnterCriticalSection(&sysloggerSection);
     513             : #endif                          /* WIN32 */
     514             : 
     515           4 :         if (pipe_eof_seen)
     516             :         {
     517             :             /*
     518             :              * seeing this message on the real stderr is annoying - so we make
     519             :              * it DEBUG1 to suppress in normal use.
     520             :              */
     521           2 :             ereport(DEBUG1,
     522             :                     (errmsg("logger shutting down")));
     523             : 
     524             :             /*
     525             :              * Normal exit from the syslogger is here.  Note that we
     526             :              * deliberately do not close syslogFile before exiting; this is to
     527             :              * allow for the possibility of elog messages being generated
     528             :              * inside proc_exit.  Regular exit() will take care of flushing
     529             :              * and closing stdio channels.
     530             :              */
     531           2 :             proc_exit(0);
     532             :         }
     533             :     }
     534             : }
     535             : 
     536             : /*
     537             :  * Postmaster subroutine to start a syslogger subprocess.
     538             :  */
     539             : int
     540         716 : SysLogger_Start(void)
     541             : {
     542             :     pid_t       sysloggerPid;
     543             :     char       *filename;
     544             : 
     545         716 :     if (!Logging_collector)
     546         714 :         return 0;
     547             : 
     548             :     /*
     549             :      * If first time through, create the pipe which will receive stderr
     550             :      * output.
     551             :      *
     552             :      * If the syslogger crashes and needs to be restarted, we continue to use
     553             :      * the same pipe (indeed must do so, since extant backends will be writing
     554             :      * into that pipe).
     555             :      *
     556             :      * This means the postmaster must continue to hold the read end of the
     557             :      * pipe open, so we can pass it down to the reincarnated syslogger. This
     558             :      * is a bit klugy but we have little choice.
     559             :      *
     560             :      * Also note that we don't bother counting the pipe FDs by calling
     561             :      * Reserve/ReleaseExternalFD.  There's no real need to account for them
     562             :      * accurately in the postmaster or syslogger process, and both ends of the
     563             :      * pipe will wind up closed in all other postmaster children.
     564             :      */
     565             : #ifndef WIN32
     566           2 :     if (syslogPipe[0] < 0)
     567             :     {
     568           2 :         if (pipe(syslogPipe) < 0)
     569           0 :             ereport(FATAL,
     570             :                     (errcode_for_socket_access(),
     571             :                      errmsg("could not create pipe for syslog: %m")));
     572             :     }
     573             : #else
     574             :     if (!syslogPipe[0])
     575             :     {
     576             :         SECURITY_ATTRIBUTES sa;
     577             : 
     578             :         memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
     579             :         sa.nLength = sizeof(SECURITY_ATTRIBUTES);
     580             :         sa.bInheritHandle = TRUE;
     581             : 
     582             :         if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
     583             :             ereport(FATAL,
     584             :                     (errcode_for_file_access(),
     585             :                      errmsg("could not create pipe for syslog: %m")));
     586             :     }
     587             : #endif
     588             : 
     589             :     /*
     590             :      * Create log directory if not present; ignore errors
     591             :      */
     592           2 :     (void) MakePGDirectory(Log_directory);
     593             : 
     594             :     /*
     595             :      * The initial logfile is created right in the postmaster, to verify that
     596             :      * the Log_directory is writable.  We save the reference time so that the
     597             :      * syslogger child process can recompute this file name.
     598             :      *
     599             :      * It might look a bit strange to re-do this during a syslogger restart,
     600             :      * but we must do so since the postmaster closed syslogFile after the
     601             :      * previous fork (and remembering that old file wouldn't be right anyway).
     602             :      * Note we always append here, we won't overwrite any existing file.  This
     603             :      * is consistent with the normal rules, because by definition this is not
     604             :      * a time-based rotation.
     605             :      */
     606           2 :     first_syslogger_file_time = time(NULL);
     607             : 
     608           2 :     filename = logfile_getname(first_syslogger_file_time, NULL);
     609             : 
     610           2 :     syslogFile = logfile_open(filename, "a", false);
     611             : 
     612           2 :     pfree(filename);
     613             : 
     614             :     /*
     615             :      * Likewise for the initial CSV log file, if that's enabled.  (Note that
     616             :      * we open syslogFile even when only CSV output is nominally enabled,
     617             :      * since some code paths will write to syslogFile anyway.)
     618             :      */
     619           2 :     if (Log_destination & LOG_DESTINATION_CSVLOG)
     620             :     {
     621           0 :         filename = logfile_getname(first_syslogger_file_time, ".csv");
     622             : 
     623           0 :         csvlogFile = logfile_open(filename, "a", false);
     624             : 
     625           0 :         pfree(filename);
     626             :     }
     627             : 
     628             : #ifdef EXEC_BACKEND
     629             :     switch ((sysloggerPid = syslogger_forkexec()))
     630             : #else
     631           2 :     switch ((sysloggerPid = fork_process()))
     632             : #endif
     633             :     {
     634           0 :         case -1:
     635           0 :             ereport(LOG,
     636             :                     (errmsg("could not fork system logger: %m")));
     637           0 :             return 0;
     638             : 
     639             : #ifndef EXEC_BACKEND
     640           2 :         case 0:
     641             :             /* in postmaster child ... */
     642           2 :             InitPostmasterChild();
     643             : 
     644             :             /* Close the postmaster's sockets */
     645           2 :             ClosePostmasterPorts(true);
     646             : 
     647             :             /* Drop our connection to postmaster's shared memory, as well */
     648           2 :             dsm_detach_all();
     649           2 :             PGSharedMemoryDetach();
     650             : 
     651             :             /* do the work */
     652           2 :             SysLoggerMain(0, NULL);
     653             :             break;
     654             : #endif
     655             : 
     656           2 :         default:
     657             :             /* success, in postmaster */
     658             : 
     659             :             /* now we redirect stderr, if not done already */
     660           2 :             if (!redirection_done)
     661             :             {
     662             : #ifdef WIN32
     663             :                 int         fd;
     664             : #endif
     665             : 
     666             :                 /*
     667             :                  * Leave a breadcrumb trail when redirecting, in case the user
     668             :                  * forgets that redirection is active and looks only at the
     669             :                  * original stderr target file.
     670             :                  */
     671           2 :                 ereport(LOG,
     672             :                         (errmsg("redirecting log output to logging collector process"),
     673             :                          errhint("Future log output will appear in directory \"%s\".",
     674             :                                  Log_directory)));
     675             : 
     676             : #ifndef WIN32
     677           2 :                 fflush(stdout);
     678           2 :                 if (dup2(syslogPipe[1], fileno(stdout)) < 0)
     679           0 :                     ereport(FATAL,
     680             :                             (errcode_for_file_access(),
     681             :                              errmsg("could not redirect stdout: %m")));
     682           2 :                 fflush(stderr);
     683           2 :                 if (dup2(syslogPipe[1], fileno(stderr)) < 0)
     684           0 :                     ereport(FATAL,
     685             :                             (errcode_for_file_access(),
     686             :                              errmsg("could not redirect stderr: %m")));
     687             :                 /* Now we are done with the write end of the pipe. */
     688           2 :                 close(syslogPipe[1]);
     689           2 :                 syslogPipe[1] = -1;
     690             : #else
     691             : 
     692             :                 /*
     693             :                  * open the pipe in binary mode and make sure stderr is binary
     694             :                  * after it's been dup'ed into, to avoid disturbing the pipe
     695             :                  * chunking protocol.
     696             :                  */
     697             :                 fflush(stderr);
     698             :                 fd = _open_osfhandle((intptr_t) syslogPipe[1],
     699             :                                      _O_APPEND | _O_BINARY);
     700             :                 if (dup2(fd, _fileno(stderr)) < 0)
     701             :                     ereport(FATAL,
     702             :                             (errcode_for_file_access(),
     703             :                              errmsg("could not redirect stderr: %m")));
     704             :                 close(fd);
     705             :                 _setmode(_fileno(stderr), _O_BINARY);
     706             : 
     707             :                 /*
     708             :                  * Now we are done with the write end of the pipe.
     709             :                  * CloseHandle() must not be called because the preceding
     710             :                  * close() closes the underlying handle.
     711             :                  */
     712             :                 syslogPipe[1] = 0;
     713             : #endif
     714           2 :                 redirection_done = true;
     715             :             }
     716             : 
     717             :             /* postmaster will never write the file(s); close 'em */
     718           2 :             fclose(syslogFile);
     719           2 :             syslogFile = NULL;
     720           2 :             if (csvlogFile != NULL)
     721             :             {
     722           0 :                 fclose(csvlogFile);
     723           0 :                 csvlogFile = NULL;
     724             :             }
     725           2 :             return (int) sysloggerPid;
     726             :     }
     727             : 
     728             :     /* we should never reach here */
     729             :     return 0;
     730             : }
     731             : 
     732             : 
     733             : #ifdef EXEC_BACKEND
     734             : 
     735             : /*
     736             :  * syslogger_forkexec() -
     737             :  *
     738             :  * Format up the arglist for, then fork and exec, a syslogger process
     739             :  */
     740             : static pid_t
     741             : syslogger_forkexec(void)
     742             : {
     743             :     char       *av[10];
     744             :     int         ac = 0;
     745             :     char        filenobuf[32];
     746             :     char        csvfilenobuf[32];
     747             : 
     748             :     av[ac++] = "postgres";
     749             :     av[ac++] = "--forklog";
     750             :     av[ac++] = NULL;            /* filled in by postmaster_forkexec */
     751             : 
     752             :     /* static variables (those not passed by write_backend_variables) */
     753             : #ifndef WIN32
     754             :     if (syslogFile != NULL)
     755             :         snprintf(filenobuf, sizeof(filenobuf), "%d",
     756             :                  fileno(syslogFile));
     757             :     else
     758             :         strcpy(filenobuf, "-1");
     759             : #else                           /* WIN32 */
     760             :     if (syslogFile != NULL)
     761             :         snprintf(filenobuf, sizeof(filenobuf), "%ld",
     762             :                  (long) _get_osfhandle(_fileno(syslogFile)));
     763             :     else
     764             :         strcpy(filenobuf, "0");
     765             : #endif                          /* WIN32 */
     766             :     av[ac++] = filenobuf;
     767             : 
     768             : #ifndef WIN32
     769             :     if (csvlogFile != NULL)
     770             :         snprintf(csvfilenobuf, sizeof(csvfilenobuf), "%d",
     771             :                  fileno(csvlogFile));
     772             :     else
     773             :         strcpy(csvfilenobuf, "-1");
     774             : #else                           /* WIN32 */
     775             :     if (csvlogFile != NULL)
     776             :         snprintf(csvfilenobuf, sizeof(csvfilenobuf), "%ld",
     777             :                  (long) _get_osfhandle(_fileno(csvlogFile)));
     778             :     else
     779             :         strcpy(csvfilenobuf, "0");
     780             : #endif                          /* WIN32 */
     781             :     av[ac++] = csvfilenobuf;
     782             : 
     783             :     av[ac] = NULL;
     784             :     Assert(ac < lengthof(av));
     785             : 
     786             :     return postmaster_forkexec(ac, av);
     787             : }
     788             : 
     789             : /*
     790             :  * syslogger_parseArgs() -
     791             :  *
     792             :  * Extract data from the arglist for exec'ed syslogger process
     793             :  */
     794             : static void
     795             : syslogger_parseArgs(int argc, char *argv[])
     796             : {
     797             :     int         fd;
     798             : 
     799             :     Assert(argc == 5);
     800             :     argv += 3;
     801             : 
     802             :     /*
     803             :      * Re-open the error output files that were opened by SysLogger_Start().
     804             :      *
     805             :      * We expect this will always succeed, which is too optimistic, but if it
     806             :      * fails there's not a lot we can do to report the problem anyway.  As
     807             :      * coded, we'll just crash on a null pointer dereference after failure...
     808             :      */
     809             : #ifndef WIN32
     810             :     fd = atoi(*argv++);
     811             :     if (fd != -1)
     812             :     {
     813             :         syslogFile = fdopen(fd, "a");
     814             :         setvbuf(syslogFile, NULL, PG_IOLBF, 0);
     815             :     }
     816             :     fd = atoi(*argv++);
     817             :     if (fd != -1)
     818             :     {
     819             :         csvlogFile = fdopen(fd, "a");
     820             :         setvbuf(csvlogFile, NULL, PG_IOLBF, 0);
     821             :     }
     822             : #else                           /* WIN32 */
     823             :     fd = atoi(*argv++);
     824             :     if (fd != 0)
     825             :     {
     826             :         fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
     827             :         if (fd > 0)
     828             :         {
     829             :             syslogFile = fdopen(fd, "a");
     830             :             setvbuf(syslogFile, NULL, PG_IOLBF, 0);
     831             :         }
     832             :     }
     833             :     fd = atoi(*argv++);
     834             :     if (fd != 0)
     835             :     {
     836             :         fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
     837             :         if (fd > 0)
     838             :         {
     839             :             csvlogFile = fdopen(fd, "a");
     840             :             setvbuf(csvlogFile, NULL, PG_IOLBF, 0);
     841             :         }
     842             :     }
     843             : #endif                          /* WIN32 */
     844             : }
     845             : #endif                          /* EXEC_BACKEND */
     846             : 
     847             : 
     848             : /* --------------------------------
     849             :  *      pipe protocol handling
     850             :  * --------------------------------
     851             :  */
     852             : 
     853             : /*
     854             :  * Process data received through the syslogger pipe.
     855             :  *
     856             :  * This routine interprets the log pipe protocol which sends log messages as
     857             :  * (hopefully atomic) chunks - such chunks are detected and reassembled here.
     858             :  *
     859             :  * The protocol has a header that starts with two nul bytes, then has a 16 bit
     860             :  * length, the pid of the sending process, and a flag to indicate if it is
     861             :  * the last chunk in a message. Incomplete chunks are saved until we read some
     862             :  * more, and non-final chunks are accumulated until we get the final chunk.
     863             :  *
     864             :  * All of this is to avoid 2 problems:
     865             :  * . partial messages being written to logfiles (messes rotation), and
     866             :  * . messages from different backends being interleaved (messages garbled).
     867             :  *
     868             :  * Any non-protocol messages are written out directly. These should only come
     869             :  * from non-PostgreSQL sources, however (e.g. third party libraries writing to
     870             :  * stderr).
     871             :  *
     872             :  * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
     873             :  * of bytes present.  On exit, any not-yet-eaten data is left-justified in
     874             :  * logbuffer, and *bytes_in_logbuffer is updated.
     875             :  */
     876             : static void
     877          22 : process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
     878             : {
     879          22 :     char       *cursor = logbuffer;
     880          22 :     int         count = *bytes_in_logbuffer;
     881          22 :     int         dest = LOG_DESTINATION_STDERR;
     882             : 
     883             :     /* While we have enough for a header, process data... */
     884          46 :     while (count >= (int) (offsetof(PipeProtoHeader, data) + 1))
     885             :     {
     886             :         PipeProtoHeader p;
     887             :         int         chunklen;
     888             : 
     889             :         /* Do we have a valid header? */
     890          24 :         memcpy(&p, cursor, offsetof(PipeProtoHeader, data));
     891          24 :         if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
     892          24 :             p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
     893          24 :             p.pid != 0 &&
     894          24 :             (p.is_last == 't' || p.is_last == 'f' ||
     895           0 :              p.is_last == 'T' || p.is_last == 'F'))
     896          24 :         {
     897             :             List       *buffer_list;
     898             :             ListCell   *cell;
     899          24 :             save_buffer *existing_slot = NULL,
     900          24 :                        *free_slot = NULL;
     901             :             StringInfo  str;
     902             : 
     903          24 :             chunklen = PIPE_HEADER_SIZE + p.len;
     904             : 
     905             :             /* Fall out of loop if we don't have the whole chunk yet */
     906          24 :             if (count < chunklen)
     907           0 :                 break;
     908             : 
     909          24 :             dest = (p.is_last == 'T' || p.is_last == 'F') ?
     910          48 :                 LOG_DESTINATION_CSVLOG : LOG_DESTINATION_STDERR;
     911             : 
     912             :             /* Locate any existing buffer for this source pid */
     913          24 :             buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
     914          24 :             foreach(cell, buffer_list)
     915             :             {
     916           0 :                 save_buffer *buf = (save_buffer *) lfirst(cell);
     917             : 
     918           0 :                 if (buf->pid == p.pid)
     919             :                 {
     920           0 :                     existing_slot = buf;
     921           0 :                     break;
     922             :                 }
     923           0 :                 if (buf->pid == 0 && free_slot == NULL)
     924           0 :                     free_slot = buf;
     925             :             }
     926             : 
     927          24 :             if (p.is_last == 'f' || p.is_last == 'F')
     928             :             {
     929             :                 /*
     930             :                  * Save a complete non-final chunk in a per-pid buffer
     931             :                  */
     932           0 :                 if (existing_slot != NULL)
     933             :                 {
     934             :                     /* Add chunk to data from preceding chunks */
     935           0 :                     str = &(existing_slot->data);
     936           0 :                     appendBinaryStringInfo(str,
     937           0 :                                            cursor + PIPE_HEADER_SIZE,
     938           0 :                                            p.len);
     939             :                 }
     940             :                 else
     941             :                 {
     942             :                     /* First chunk of message, save in a new buffer */
     943           0 :                     if (free_slot == NULL)
     944             :                     {
     945             :                         /*
     946             :                          * Need a free slot, but there isn't one in the list,
     947             :                          * so create a new one and extend the list with it.
     948             :                          */
     949           0 :                         free_slot = palloc(sizeof(save_buffer));
     950           0 :                         buffer_list = lappend(buffer_list, free_slot);
     951           0 :                         buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
     952             :                     }
     953           0 :                     free_slot->pid = p.pid;
     954           0 :                     str = &(free_slot->data);
     955           0 :                     initStringInfo(str);
     956           0 :                     appendBinaryStringInfo(str,
     957           0 :                                            cursor + PIPE_HEADER_SIZE,
     958           0 :                                            p.len);
     959             :                 }
     960             :             }
     961             :             else
     962             :             {
     963             :                 /*
     964             :                  * Final chunk --- add it to anything saved for that pid, and
     965             :                  * either way write the whole thing out.
     966             :                  */
     967          24 :                 if (existing_slot != NULL)
     968             :                 {
     969           0 :                     str = &(existing_slot->data);
     970           0 :                     appendBinaryStringInfo(str,
     971           0 :                                            cursor + PIPE_HEADER_SIZE,
     972           0 :                                            p.len);
     973           0 :                     write_syslogger_file(str->data, str->len, dest);
     974             :                     /* Mark the buffer unused, and reclaim string storage */
     975           0 :                     existing_slot->pid = 0;
     976           0 :                     pfree(str->data);
     977             :                 }
     978             :                 else
     979             :                 {
     980             :                     /* The whole message was one chunk, evidently. */
     981          24 :                     write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
     982             :                                          dest);
     983             :                 }
     984             :             }
     985             : 
     986             :             /* Finished processing this chunk */
     987          24 :             cursor += chunklen;
     988          24 :             count -= chunklen;
     989             :         }
     990             :         else
     991             :         {
     992             :             /* Process non-protocol data */
     993             : 
     994             :             /*
     995             :              * Look for the start of a protocol header.  If found, dump data
     996             :              * up to there and repeat the loop.  Otherwise, dump it all and
     997             :              * fall out of the loop.  (Note: we want to dump it all if at all
     998             :              * possible, so as to avoid dividing non-protocol messages across
     999             :              * logfiles.  We expect that in many scenarios, a non-protocol
    1000             :              * message will arrive all in one read(), and we want to respect
    1001             :              * the read() boundary if possible.)
    1002             :              */
    1003           0 :             for (chunklen = 1; chunklen < count; chunklen++)
    1004             :             {
    1005           0 :                 if (cursor[chunklen] == '\0')
    1006           0 :                     break;
    1007             :             }
    1008             :             /* fall back on the stderr log as the destination */
    1009           0 :             write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
    1010           0 :             cursor += chunklen;
    1011           0 :             count -= chunklen;
    1012             :         }
    1013             :     }
    1014             : 
    1015             :     /* We don't have a full chunk, so left-align what remains in the buffer */
    1016          22 :     if (count > 0 && cursor != logbuffer)
    1017           0 :         memmove(logbuffer, cursor, count);
    1018          22 :     *bytes_in_logbuffer = count;
    1019          22 : }
    1020             : 
    1021             : /*
    1022             :  * Force out any buffered data
    1023             :  *
    1024             :  * This is currently used only at syslogger shutdown, but could perhaps be
    1025             :  * useful at other times, so it is careful to leave things in a clean state.
    1026             :  */
    1027             : static void
    1028           2 : flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
    1029             : {
    1030             :     int         i;
    1031             : 
    1032             :     /* Dump any incomplete protocol messages */
    1033         514 :     for (i = 0; i < NBUFFER_LISTS; i++)
    1034             :     {
    1035         512 :         List       *list = buffer_lists[i];
    1036             :         ListCell   *cell;
    1037             : 
    1038         512 :         foreach(cell, list)
    1039             :         {
    1040           0 :             save_buffer *buf = (save_buffer *) lfirst(cell);
    1041             : 
    1042           0 :             if (buf->pid != 0)
    1043             :             {
    1044           0 :                 StringInfo  str = &(buf->data);
    1045             : 
    1046           0 :                 write_syslogger_file(str->data, str->len,
    1047             :                                      LOG_DESTINATION_STDERR);
    1048             :                 /* Mark the buffer unused, and reclaim string storage */
    1049           0 :                 buf->pid = 0;
    1050           0 :                 pfree(str->data);
    1051             :             }
    1052             :         }
    1053             :     }
    1054             : 
    1055             :     /*
    1056             :      * Force out any remaining pipe data as-is; we don't bother trying to
    1057             :      * remove any protocol headers that may exist in it.
    1058             :      */
    1059           2 :     if (*bytes_in_logbuffer > 0)
    1060           0 :         write_syslogger_file(logbuffer, *bytes_in_logbuffer,
    1061             :                              LOG_DESTINATION_STDERR);
    1062           2 :     *bytes_in_logbuffer = 0;
    1063           2 : }
    1064             : 
    1065             : 
    1066             : /* --------------------------------
    1067             :  *      logfile routines
    1068             :  * --------------------------------
    1069             :  */
    1070             : 
    1071             : /*
    1072             :  * Write text to the currently open logfile
    1073             :  *
    1074             :  * This is exported so that elog.c can call it when MyBackendType is B_LOGGER.
    1075             :  * This allows the syslogger process to record elog messages of its own,
    1076             :  * even though its stderr does not point at the syslog pipe.
    1077             :  */
    1078             : void
    1079          24 : write_syslogger_file(const char *buffer, int count, int destination)
    1080             : {
    1081             :     int         rc;
    1082             :     FILE       *logfile;
    1083             : 
    1084             :     /*
    1085             :      * If we're told to write to csvlogFile, but it's not open, dump the data
    1086             :      * to syslogFile (which is always open) instead.  This can happen if CSV
    1087             :      * output is enabled after postmaster start and we've been unable to open
    1088             :      * csvlogFile.  There are also race conditions during a parameter change
    1089             :      * whereby backends might send us CSV output before we open csvlogFile or
    1090             :      * after we close it.  Writing CSV-formatted output to the regular log
    1091             :      * file isn't great, but it beats dropping log output on the floor.
    1092             :      *
    1093             :      * Think not to improve this by trying to open csvlogFile on-the-fly.  Any
    1094             :      * failure in that would lead to recursion.
    1095             :      */
    1096          24 :     logfile = (destination == LOG_DESTINATION_CSVLOG &&
    1097          24 :                csvlogFile != NULL) ? csvlogFile : syslogFile;
    1098             : 
    1099          24 :     rc = fwrite(buffer, 1, count, logfile);
    1100             : 
    1101             :     /*
    1102             :      * Try to report any failure.  We mustn't use ereport because it would
    1103             :      * just recurse right back here, but write_stderr is OK: it will write
    1104             :      * either to the postmaster's original stderr, or to /dev/null, but never
    1105             :      * to our input pipe which would result in a different sort of looping.
    1106             :      */
    1107          24 :     if (rc != count)
    1108           0 :         write_stderr("could not write to log file: %s\n", strerror(errno));
    1109          24 : }
    1110             : 
    1111             : #ifdef WIN32
    1112             : 
    1113             : /*
    1114             :  * Worker thread to transfer data from the pipe to the current logfile.
    1115             :  *
    1116             :  * We need this because on Windows, WaitForMultipleObjects does not work on
    1117             :  * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
    1118             :  * allow for SIGHUP; and select is for sockets only.
    1119             :  */
    1120             : static unsigned int __stdcall
    1121             : pipeThread(void *arg)
    1122             : {
    1123             :     char        logbuffer[READ_BUF_SIZE];
    1124             :     int         bytes_in_logbuffer = 0;
    1125             : 
    1126             :     for (;;)
    1127             :     {
    1128             :         DWORD       bytesRead;
    1129             :         BOOL        result;
    1130             : 
    1131             :         result = ReadFile(syslogPipe[0],
    1132             :                           logbuffer + bytes_in_logbuffer,
    1133             :                           sizeof(logbuffer) - bytes_in_logbuffer,
    1134             :                           &bytesRead, 0);
    1135             : 
    1136             :         /*
    1137             :          * Enter critical section before doing anything that might touch
    1138             :          * global state shared by the main thread. Anything that uses
    1139             :          * palloc()/pfree() in particular are not safe outside the critical
    1140             :          * section.
    1141             :          */
    1142             :         EnterCriticalSection(&sysloggerSection);
    1143             :         if (!result)
    1144             :         {
    1145             :             DWORD       error = GetLastError();
    1146             : 
    1147             :             if (error == ERROR_HANDLE_EOF ||
    1148             :                 error == ERROR_BROKEN_PIPE)
    1149             :                 break;
    1150             :             _dosmaperr(error);
    1151             :             ereport(LOG,
    1152             :                     (errcode_for_file_access(),
    1153             :                      errmsg("could not read from logger pipe: %m")));
    1154             :         }
    1155             :         else if (bytesRead > 0)
    1156             :         {
    1157             :             bytes_in_logbuffer += bytesRead;
    1158             :             process_pipe_input(logbuffer, &bytes_in_logbuffer);
    1159             :         }
    1160             : 
    1161             :         /*
    1162             :          * If we've filled the current logfile, nudge the main thread to do a
    1163             :          * log rotation.
    1164             :          */
    1165             :         if (Log_RotationSize > 0)
    1166             :         {
    1167             :             if (ftell(syslogFile) >= Log_RotationSize * 1024L ||
    1168             :                 (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L))
    1169             :                 SetLatch(MyLatch);
    1170             :         }
    1171             :         LeaveCriticalSection(&sysloggerSection);
    1172             :     }
    1173             : 
    1174             :     /* We exit the above loop only upon detecting pipe EOF */
    1175             :     pipe_eof_seen = true;
    1176             : 
    1177             :     /* if there's any data left then force it out now */
    1178             :     flush_pipe_input(logbuffer, &bytes_in_logbuffer);
    1179             : 
    1180             :     /* set the latch to waken the main thread, which will quit */
    1181             :     SetLatch(MyLatch);
    1182             : 
    1183             :     LeaveCriticalSection(&sysloggerSection);
    1184             :     _endthread();
    1185             :     return 0;
    1186             : }
    1187             : #endif                          /* WIN32 */
    1188             : 
    1189             : /*
    1190             :  * Open a new logfile with proper permissions and buffering options.
    1191             :  *
    1192             :  * If allow_errors is true, we just log any open failure and return NULL
    1193             :  * (with errno still correct for the fopen failure).
    1194             :  * Otherwise, errors are treated as fatal.
    1195             :  */
    1196             : static FILE *
    1197           4 : logfile_open(const char *filename, const char *mode, bool allow_errors)
    1198             : {
    1199             :     FILE       *fh;
    1200             :     mode_t      oumask;
    1201             : 
    1202             :     /*
    1203             :      * Note we do not let Log_file_mode disable IWUSR, since we certainly want
    1204             :      * to be able to write the files ourselves.
    1205             :      */
    1206           4 :     oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
    1207           4 :     fh = fopen(filename, mode);
    1208           4 :     umask(oumask);
    1209             : 
    1210           4 :     if (fh)
    1211             :     {
    1212           4 :         setvbuf(fh, NULL, PG_IOLBF, 0);
    1213             : 
    1214             : #ifdef WIN32
    1215             :         /* use CRLF line endings on Windows */
    1216             :         _setmode(_fileno(fh), _O_TEXT);
    1217             : #endif
    1218             :     }
    1219             :     else
    1220             :     {
    1221           0 :         int         save_errno = errno;
    1222             : 
    1223           0 :         ereport(allow_errors ? LOG : FATAL,
    1224             :                 (errcode_for_file_access(),
    1225             :                  errmsg("could not open log file \"%s\": %m",
    1226             :                         filename)));
    1227           0 :         errno = save_errno;
    1228             :     }
    1229             : 
    1230           4 :     return fh;
    1231             : }
    1232             : 
    1233             : /*
    1234             :  * perform logfile rotation
    1235             :  */
    1236             : static void
    1237           2 : logfile_rotate(bool time_based_rotation, int size_rotation_for)
    1238             : {
    1239             :     char       *filename;
    1240           2 :     char       *csvfilename = NULL;
    1241             :     pg_time_t   fntime;
    1242             :     FILE       *fh;
    1243             : 
    1244           2 :     rotation_requested = false;
    1245             : 
    1246             :     /*
    1247             :      * When doing a time-based rotation, invent the new logfile name based on
    1248             :      * the planned rotation time, not current time, to avoid "slippage" in the
    1249             :      * file name when we don't do the rotation immediately.
    1250             :      */
    1251           2 :     if (time_based_rotation)
    1252           0 :         fntime = next_rotation_time;
    1253             :     else
    1254           2 :         fntime = time(NULL);
    1255           2 :     filename = logfile_getname(fntime, NULL);
    1256           2 :     if (Log_destination & LOG_DESTINATION_CSVLOG)
    1257           0 :         csvfilename = logfile_getname(fntime, ".csv");
    1258             : 
    1259             :     /*
    1260             :      * Decide whether to overwrite or append.  We can overwrite if (a)
    1261             :      * Log_truncate_on_rotation is set, (b) the rotation was triggered by
    1262             :      * elapsed time and not something else, and (c) the computed file name is
    1263             :      * different from what we were previously logging into.
    1264             :      *
    1265             :      * Note: last_file_name should never be NULL here, but if it is, append.
    1266             :      */
    1267           2 :     if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
    1268             :     {
    1269           2 :         if (Log_truncate_on_rotation && time_based_rotation &&
    1270           0 :             last_file_name != NULL &&
    1271           0 :             strcmp(filename, last_file_name) != 0)
    1272           0 :             fh = logfile_open(filename, "w", true);
    1273             :         else
    1274           2 :             fh = logfile_open(filename, "a", true);
    1275             : 
    1276           2 :         if (!fh)
    1277             :         {
    1278             :             /*
    1279             :              * ENFILE/EMFILE are not too surprising on a busy system; just
    1280             :              * keep using the old file till we manage to get a new one.
    1281             :              * Otherwise, assume something's wrong with Log_directory and stop
    1282             :              * trying to create files.
    1283             :              */
    1284           0 :             if (errno != ENFILE && errno != EMFILE)
    1285             :             {
    1286           0 :                 ereport(LOG,
    1287             :                         (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
    1288           0 :                 rotation_disabled = true;
    1289             :             }
    1290             : 
    1291           0 :             if (filename)
    1292           0 :                 pfree(filename);
    1293           0 :             if (csvfilename)
    1294           0 :                 pfree(csvfilename);
    1295           0 :             return;
    1296             :         }
    1297             : 
    1298           2 :         fclose(syslogFile);
    1299           2 :         syslogFile = fh;
    1300             : 
    1301             :         /* instead of pfree'ing filename, remember it for next time */
    1302           2 :         if (last_file_name != NULL)
    1303           2 :             pfree(last_file_name);
    1304           2 :         last_file_name = filename;
    1305           2 :         filename = NULL;
    1306             :     }
    1307             : 
    1308             :     /*
    1309             :      * Same as above, but for csv file.  Note that if LOG_DESTINATION_CSVLOG
    1310             :      * was just turned on, we might have to open csvlogFile here though it was
    1311             :      * not open before.  In such a case we'll append not overwrite (since
    1312             :      * last_csv_file_name will be NULL); that is consistent with the normal
    1313             :      * rules since it's not a time-based rotation.
    1314             :      */
    1315           2 :     if ((Log_destination & LOG_DESTINATION_CSVLOG) &&
    1316           0 :         (csvlogFile == NULL ||
    1317           0 :          time_based_rotation || (size_rotation_for & LOG_DESTINATION_CSVLOG)))
    1318             :     {
    1319           0 :         if (Log_truncate_on_rotation && time_based_rotation &&
    1320           0 :             last_csv_file_name != NULL &&
    1321           0 :             strcmp(csvfilename, last_csv_file_name) != 0)
    1322           0 :             fh = logfile_open(csvfilename, "w", true);
    1323             :         else
    1324           0 :             fh = logfile_open(csvfilename, "a", true);
    1325             : 
    1326           0 :         if (!fh)
    1327             :         {
    1328             :             /*
    1329             :              * ENFILE/EMFILE are not too surprising on a busy system; just
    1330             :              * keep using the old file till we manage to get a new one.
    1331             :              * Otherwise, assume something's wrong with Log_directory and stop
    1332             :              * trying to create files.
    1333             :              */
    1334           0 :             if (errno != ENFILE && errno != EMFILE)
    1335             :             {
    1336           0 :                 ereport(LOG,
    1337             :                         (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
    1338           0 :                 rotation_disabled = true;
    1339             :             }
    1340             : 
    1341           0 :             if (filename)
    1342           0 :                 pfree(filename);
    1343           0 :             if (csvfilename)
    1344           0 :                 pfree(csvfilename);
    1345           0 :             return;
    1346             :         }
    1347             : 
    1348           0 :         if (csvlogFile != NULL)
    1349           0 :             fclose(csvlogFile);
    1350           0 :         csvlogFile = fh;
    1351             : 
    1352             :         /* instead of pfree'ing filename, remember it for next time */
    1353           0 :         if (last_csv_file_name != NULL)
    1354           0 :             pfree(last_csv_file_name);
    1355           0 :         last_csv_file_name = csvfilename;
    1356           0 :         csvfilename = NULL;
    1357             :     }
    1358           2 :     else if (!(Log_destination & LOG_DESTINATION_CSVLOG) &&
    1359           2 :              csvlogFile != NULL)
    1360             :     {
    1361             :         /* CSVLOG was just turned off, so close the old file */
    1362           0 :         fclose(csvlogFile);
    1363           0 :         csvlogFile = NULL;
    1364           0 :         if (last_csv_file_name != NULL)
    1365           0 :             pfree(last_csv_file_name);
    1366           0 :         last_csv_file_name = NULL;
    1367             :     }
    1368             : 
    1369           2 :     if (filename)
    1370           0 :         pfree(filename);
    1371           2 :     if (csvfilename)
    1372           0 :         pfree(csvfilename);
    1373             : 
    1374           2 :     update_metainfo_datafile();
    1375             : 
    1376           2 :     set_next_rotation_time();
    1377             : }
    1378             : 
    1379             : 
    1380             : /*
    1381             :  * construct logfile name using timestamp information
    1382             :  *
    1383             :  * If suffix isn't NULL, append it to the name, replacing any ".log"
    1384             :  * that may be in the pattern.
    1385             :  *
    1386             :  * Result is palloc'd.
    1387             :  */
    1388             : static char *
    1389           6 : logfile_getname(pg_time_t timestamp, const char *suffix)
    1390             : {
    1391             :     char       *filename;
    1392             :     int         len;
    1393             : 
    1394           6 :     filename = palloc(MAXPGPATH);
    1395             : 
    1396           6 :     snprintf(filename, MAXPGPATH, "%s/", Log_directory);
    1397             : 
    1398           6 :     len = strlen(filename);
    1399             : 
    1400             :     /* treat Log_filename as a strftime pattern */
    1401           6 :     pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
    1402           6 :                 pg_localtime(&timestamp, log_timezone));
    1403             : 
    1404           6 :     if (suffix != NULL)
    1405             :     {
    1406           0 :         len = strlen(filename);
    1407           0 :         if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
    1408           0 :             len -= 4;
    1409           0 :         strlcpy(filename + len, suffix, MAXPGPATH - len);
    1410             :     }
    1411             : 
    1412           6 :     return filename;
    1413             : }
    1414             : 
    1415             : /*
    1416             :  * Determine the next planned rotation time, and store in next_rotation_time.
    1417             :  */
    1418             : static void
    1419           4 : set_next_rotation_time(void)
    1420             : {
    1421             :     pg_time_t   now;
    1422             :     struct pg_tm *tm;
    1423             :     int         rotinterval;
    1424             : 
    1425             :     /* nothing to do if time-based rotation is disabled */
    1426           4 :     if (Log_RotationAge <= 0)
    1427           0 :         return;
    1428             : 
    1429             :     /*
    1430             :      * The requirements here are to choose the next time > now that is a
    1431             :      * "multiple" of the log rotation interval.  "Multiple" can be interpreted
    1432             :      * fairly loosely.  In this version we align to log_timezone rather than
    1433             :      * GMT.
    1434             :      */
    1435           4 :     rotinterval = Log_RotationAge * SECS_PER_MINUTE;    /* convert to seconds */
    1436           4 :     now = (pg_time_t) time(NULL);
    1437           4 :     tm = pg_localtime(&now, log_timezone);
    1438           4 :     now += tm->tm_gmtoff;
    1439           4 :     now -= now % rotinterval;
    1440           4 :     now += rotinterval;
    1441           4 :     now -= tm->tm_gmtoff;
    1442           4 :     next_rotation_time = now;
    1443             : }
    1444             : 
    1445             : /*
    1446             :  * Store the name of the file(s) where the log collector, when enabled, writes
    1447             :  * log messages.  Useful for finding the name(s) of the current log file(s)
    1448             :  * when there is time-based logfile rotation.  Filenames are stored in a
    1449             :  * temporary file and which is renamed into the final destination for
    1450             :  * atomicity.  The file is opened with the same permissions as what gets
    1451             :  * created in the data directory and has proper buffering options.
    1452             :  */
    1453             : static void
    1454           4 : update_metainfo_datafile(void)
    1455             : {
    1456             :     FILE       *fh;
    1457             :     mode_t      oumask;
    1458             : 
    1459           4 :     if (!(Log_destination & LOG_DESTINATION_STDERR) &&
    1460           0 :         !(Log_destination & LOG_DESTINATION_CSVLOG))
    1461             :     {
    1462           0 :         if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
    1463           0 :             ereport(LOG,
    1464             :                     (errcode_for_file_access(),
    1465             :                      errmsg("could not remove file \"%s\": %m",
    1466             :                             LOG_METAINFO_DATAFILE)));
    1467           0 :         return;
    1468             :     }
    1469             : 
    1470             :     /* use the same permissions as the data directory for the new file */
    1471           4 :     oumask = umask(pg_mode_mask);
    1472           4 :     fh = fopen(LOG_METAINFO_DATAFILE_TMP, "w");
    1473           4 :     umask(oumask);
    1474             : 
    1475           4 :     if (fh)
    1476             :     {
    1477           4 :         setvbuf(fh, NULL, PG_IOLBF, 0);
    1478             : 
    1479             : #ifdef WIN32
    1480             :         /* use CRLF line endings on Windows */
    1481             :         _setmode(_fileno(fh), _O_TEXT);
    1482             : #endif
    1483             :     }
    1484             :     else
    1485             :     {
    1486           0 :         ereport(LOG,
    1487             :                 (errcode_for_file_access(),
    1488             :                  errmsg("could not open file \"%s\": %m",
    1489             :                         LOG_METAINFO_DATAFILE_TMP)));
    1490           0 :         return;
    1491             :     }
    1492             : 
    1493           4 :     if (last_file_name && (Log_destination & LOG_DESTINATION_STDERR))
    1494             :     {
    1495           4 :         if (fprintf(fh, "stderr %s\n", last_file_name) < 0)
    1496             :         {
    1497           0 :             ereport(LOG,
    1498             :                     (errcode_for_file_access(),
    1499             :                      errmsg("could not write file \"%s\": %m",
    1500             :                             LOG_METAINFO_DATAFILE_TMP)));
    1501           0 :             fclose(fh);
    1502           0 :             return;
    1503             :         }
    1504             :     }
    1505             : 
    1506           4 :     if (last_csv_file_name && (Log_destination & LOG_DESTINATION_CSVLOG))
    1507             :     {
    1508           0 :         if (fprintf(fh, "csvlog %s\n", last_csv_file_name) < 0)
    1509             :         {
    1510           0 :             ereport(LOG,
    1511             :                     (errcode_for_file_access(),
    1512             :                      errmsg("could not write file \"%s\": %m",
    1513             :                             LOG_METAINFO_DATAFILE_TMP)));
    1514           0 :             fclose(fh);
    1515           0 :             return;
    1516             :         }
    1517             :     }
    1518           4 :     fclose(fh);
    1519             : 
    1520           4 :     if (rename(LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE) != 0)
    1521           0 :         ereport(LOG,
    1522             :                 (errcode_for_file_access(),
    1523             :                  errmsg("could not rename file \"%s\" to \"%s\": %m",
    1524             :                         LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE)));
    1525             : }
    1526             : 
    1527             : /* --------------------------------
    1528             :  *      signal handler routines
    1529             :  * --------------------------------
    1530             :  */
    1531             : 
    1532             : /*
    1533             :  * Check to see if a log rotation request has arrived.  Should be
    1534             :  * called by postmaster after receiving SIGUSR1.
    1535             :  */
    1536             : bool
    1537           2 : CheckLogrotateSignal(void)
    1538             : {
    1539             :     struct stat stat_buf;
    1540             : 
    1541           2 :     if (stat(LOGROTATE_SIGNAL_FILE, &stat_buf) == 0)
    1542           2 :         return true;
    1543             : 
    1544           0 :     return false;
    1545             : }
    1546             : 
    1547             : /*
    1548             :  * Remove the file signaling a log rotation request.
    1549             :  */
    1550             : void
    1551         718 : RemoveLogrotateSignalFiles(void)
    1552             : {
    1553         718 :     unlink(LOGROTATE_SIGNAL_FILE);
    1554         718 : }
    1555             : 
    1556             : /* SIGHUP: set flag to reload config file */
    1557             : static void
    1558           0 : sigHupHandler(SIGNAL_ARGS)
    1559             : {
    1560           0 :     int         save_errno = errno;
    1561             : 
    1562           0 :     got_SIGHUP = true;
    1563           0 :     SetLatch(MyLatch);
    1564             : 
    1565           0 :     errno = save_errno;
    1566           0 : }
    1567             : 
    1568             : /* SIGUSR1: set flag to rotate logfile */
    1569             : static void
    1570           2 : sigUsr1Handler(SIGNAL_ARGS)
    1571             : {
    1572           2 :     int         save_errno = errno;
    1573             : 
    1574           2 :     rotation_requested = true;
    1575           2 :     SetLatch(MyLatch);
    1576             : 
    1577           2 :     errno = save_errno;
    1578           2 : }

Generated by: LCOV version 1.13