/src/postgres/src/backend/postmaster/syslogger.c

Source
/*-------------------------------------------------------------------------
 *
 * syslogger.c
 *
 * The system logger (syslogger) appeared in Postgres 8.0. It catches all
 * stderr output from the postmaster, backends, and other subprocesses
 * by redirecting to a pipe, and writes it to a set of logfiles.
 * It's possible to have size and age limits for the logfile configured
 * in postgresql.conf. If these limits are reached or passed, the
 * current logfile is closed and a new one is created (rotated).
 * The logfiles are stored in a subdirectory (configurable in
 * postgresql.conf), using a user-selectable naming scheme.
 *
 * Author: Andreas Pflug <pgadmin@pse-consulting.de>
 *
 * Copyright (c) 2004-2026, PostgreSQL Global Development Group
 *
 *
 * IDENTIFICATION
 *    src/backend/postmaster/syslogger.c
 *
 *-------------------------------------------------------------------------
 */
#include "postgres.h"

#include <fcntl.h>
#include <limits.h>
#include <signal.h>
#include <time.h>
#include <unistd.h>
#include <sys/stat.h>
#include <sys/time.h>

#include "common/file_perm.h"
#include "lib/stringinfo.h"
#include "libpq/pqsignal.h"
#include "miscadmin.h"
#include "nodes/pg_list.h"
#include "pgstat.h"
#include "pgtime.h"
#include "port/pg_bitutils.h"
#include "postmaster/interrupt.h"
#include "postmaster/postmaster.h"
#include "postmaster/syslogger.h"
#include "storage/dsm.h"
#include "storage/fd.h"
#include "storage/ipc.h"
#include "storage/latch.h"
#include "storage/pg_shmem.h"
#include "tcop/tcopprot.h"
#include "utils/guc.h"
#include "utils/memutils.h"
#include "utils/ps_status.h"
#include "utils/wait_event.h"

/*
 * We read() into a temp buffer twice as big as a chunk, so that any fragment
 * left after processing can be moved down to the front and we'll still have
 * room to read a full chunk.
 */
#define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)

/* Log rotation signal file path, relative to $PGDATA */
#define LOGROTATE_SIGNAL_FILE "logrotate"


/*
 * GUC parameters.  Logging_collector cannot be changed after postmaster
 * start, but the rest can change at SIGHUP.
 */
bool    Logging_collector = false;
int     Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
int     Log_RotationSize = 10 * 1024;
char     *Log_directory = NULL;
char     *Log_filename = NULL;
bool    Log_truncate_on_rotation = false;
int     Log_file_mode = S_IRUSR | S_IWUSR;

/*
 * Indicates to be running in the syslogger process, and that the logging
 * file descriptor(s) have been set up.
 */
bool    syslogger_setup_done = false;

/*
 * Private state
 */
static pg_time_t next_rotation_time;
static bool pipe_eof_seen = false;
static bool rotation_disabled = false;
static FILE *syslogFile = NULL;
static FILE *csvlogFile = NULL;
static FILE *jsonlogFile = NULL;
NON_EXEC_STATIC pg_time_t first_syslogger_file_time = 0;
static char *last_sys_file_name = NULL;
static char *last_csv_file_name = NULL;
static char *last_json_file_name = NULL;

/*
 * Buffers for saving partial messages from different backends.
 *
 * Keep NBUFFER_LISTS lists of these, with the entry for a given source pid
 * being in the list numbered (pid % NBUFFER_LISTS), so as to cut down on
 * the number of entries we have to examine for any one incoming message.
 * There must never be more than one entry for the same source pid.
 *
 * An inactive buffer is not removed from its list, just held for re-use.
 * An inactive buffer has pid == 0 and undefined contents of data.
 */
typedef struct
{
  int32   pid;      /* PID of source process */
  StringInfoData data;    /* accumulated data, as a StringInfo */
} save_buffer;

#define NBUFFER_LISTS 256
static List *buffer_lists[NBUFFER_LISTS];

/* These must be exported for EXEC_BACKEND case ... annoying */
#ifndef WIN32
int     syslogPipe[2] = {-1, -1};
#else
HANDLE    syslogPipe[2] = {0, 0};
#endif

#ifdef WIN32
static HANDLE threadHandle = 0;
static CRITICAL_SECTION sysloggerSection;
#endif

/*
 * Flags set by interrupt handlers for later service in the main loop.
 */
static volatile sig_atomic_t rotation_requested = false;


/* Local subroutines */
#ifdef EXEC_BACKEND
static int  syslogger_fdget(FILE *file);
static FILE *syslogger_fdopen(int fd);
#endif
static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
static FILE *logfile_open(const char *filename, const char *mode,
              bool allow_errors);

#ifdef WIN32
static unsigned int __stdcall pipeThread(void *arg);
#endif
static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
static bool logfile_rotate_dest(bool time_based_rotation,
                int size_rotation_for, pg_time_t fntime,
                int target_dest, char **last_file_name,
                FILE **logFile);
static char *logfile_getname(pg_time_t timestamp, const char *suffix);
static void set_next_rotation_time(void);
static void sigUsr1Handler(SIGNAL_ARGS);
static void update_metainfo_datafile(void);

typedef struct
{
  int     syslogFile;
  int     csvlogFile;
  int     jsonlogFile;
} SysloggerStartupData;

/*
 * Main entry point for syslogger process
 * argc/argv parameters are valid only in EXEC_BACKEND case.
 */
void
SysLoggerMain(const void *startup_data, size_t startup_data_len)
{
#ifndef WIN32
  char    logbuffer[READ_BUF_SIZE];
  int     bytes_in_logbuffer = 0;
#endif
  char     *currentLogDir;
  char     *currentLogFilename;
  int     currentLogRotationAge;
  pg_time_t now;
  WaitEventSet *wes;

#ifndef EXEC_BACKEND

  /*
   * In !EXEC_BACKEND, syslogger is immediately ready to take over: the
   * output files were already opened by postmaster before forking.  For the
   * other case we must wait until the file descriptors have been restored,
   * below.
   */
  syslogger_setup_done = true;
#endif

  /*
   * Re-open the error output files that were opened by SysLogger_Start().
   *
   * We expect this will always succeed, which is too optimistic, but if it
   * fails there's not a lot we can do to report the problem anyway.  As
   * coded, we'll just crash on a null pointer dereference after failure...
   */
#ifdef EXEC_BACKEND
  {
    const SysloggerStartupData *slsdata = startup_data;

    Assert(startup_data_len == sizeof(*slsdata));
    syslogFile = syslogger_fdopen(slsdata->syslogFile);
    csvlogFile = syslogger_fdopen(slsdata->csvlogFile);
    jsonlogFile = syslogger_fdopen(slsdata->jsonlogFile);

    syslogger_setup_done = true;
  }
#else
  Assert(startup_data_len == 0);
#endif

  /*
   * Now that we're done reading the startup data, release postmaster's
   * working memory context.
   */
  if (PostmasterContext)
  {
    MemoryContextDelete(PostmasterContext);
    PostmasterContext = NULL;
  }

  now = MyStartTime;

  init_ps_display(NULL);

  /*
   * If we restarted, our stderr is already redirected into our own input
   * pipe.  This is of course pretty useless, not to mention that it
   * interferes with detecting pipe EOF.  Point stderr to /dev/null. This
   * assumes that all interesting messages generated in the syslogger will
   * come through elog.c and will be sent to write_syslogger_file.
   */
  if (redirection_done)
  {
    int     fd = open(DEVNULL, O_WRONLY, 0);

    /*
     * The closes might look redundant, but they are not: we want to be
     * darn sure the pipe gets closed even if the open failed.  We can
     * survive running with stderr pointing nowhere, but we can't afford
     * to have extra pipe input descriptors hanging around.
     *
     * As we're just trying to reset these to go to DEVNULL, there's not
     * much point in checking for failure from the close/dup2 calls here,
     * if they fail then presumably the file descriptors are closed and
     * any writes will go into the bitbucket anyway.
     */
    close(STDOUT_FILENO);
    close(STDERR_FILENO);
    if (fd != -1)
    {
      (void) dup2(fd, STDOUT_FILENO);
      (void) dup2(fd, STDERR_FILENO);
      close(fd);
    }
  }

  /*
   * Syslogger's own stderr can't be the syslogPipe, so set it back to text
   * mode if we didn't just close it. (It was set to binary in
   * SubPostmasterMain).
   */
#ifdef WIN32
  else
    _setmode(STDERR_FILENO, _O_TEXT);
#endif

  /*
   * Also close our copy of the write end of the pipe.  This is needed to
   * ensure we can detect pipe EOF correctly.  (But note that in the restart
   * case, the postmaster already did this.)
   */
#ifndef WIN32
  if (syslogPipe[1] >= 0)
    close(syslogPipe[1]);
  syslogPipe[1] = -1;
#else
  if (syslogPipe[1])
    CloseHandle(syslogPipe[1]);
  syslogPipe[1] = 0;
#endif

  /*
   * Properly accept or ignore signals the postmaster might send us
   *
   * Note: we ignore all termination signals, and instead exit only when all
   * upstream processes are gone, to ensure we don't miss any dying gasps of
   * broken backends...
   */

  pqsignal(SIGHUP, SignalHandlerForConfigReload); /* set flag to read config
                           * file */
  pqsignal(SIGINT, PG_SIG_IGN);
  pqsignal(SIGTERM, PG_SIG_IGN);
  pqsignal(SIGQUIT, PG_SIG_IGN);
  pqsignal(SIGALRM, PG_SIG_IGN);
  pqsignal(SIGPIPE, PG_SIG_IGN);
  pqsignal(SIGUSR1, sigUsr1Handler);  /* request log rotation */
  pqsignal(SIGUSR2, PG_SIG_IGN);

  /*
   * Reset some signals that are accepted by postmaster but not here
   */
  pqsignal(SIGCHLD, PG_SIG_DFL);

  sigprocmask(SIG_SETMASK, &UnBlockSig, NULL);

#ifdef WIN32
  /* Fire up separate data transfer thread */
  InitializeCriticalSection(&sysloggerSection);
  EnterCriticalSection(&sysloggerSection);

  threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
  if (threadHandle == 0)
    elog(FATAL, "could not create syslogger data transfer thread: %m");
#endif              /* WIN32 */

  /*
   * Remember active logfiles' name(s).  We recompute 'em from the reference
   * time because passing down just the pg_time_t is a lot cheaper than
   * passing a whole file path in the EXEC_BACKEND case.
   */
  last_sys_file_name = logfile_getname(first_syslogger_file_time, NULL);
  if (csvlogFile != NULL)
    last_csv_file_name = logfile_getname(first_syslogger_file_time, ".csv");
  if (jsonlogFile != NULL)
    last_json_file_name = logfile_getname(first_syslogger_file_time, ".json");

  /* remember active logfile parameters */
  currentLogDir = pstrdup(Log_directory);
  currentLogFilename = pstrdup(Log_filename);
  currentLogRotationAge = Log_RotationAge;
  /* set next planned rotation time */
  set_next_rotation_time();
  update_metainfo_datafile();

  /*
   * Reset whereToSendOutput, as the postmaster will do (but hasn't yet, at
   * the point where we forked).  This prevents duplicate output of messages
   * from syslogger itself.
   */
  whereToSendOutput = DestNone;

  /*
   * Set up a reusable WaitEventSet object we'll use to wait for our latch,
   * and (except on Windows) our socket.
   *
   * Unlike all other postmaster child processes, we'll ignore postmaster
   * death because we want to collect final log output from all backends and
   * then exit last.  We'll do that by running until we see EOF on the
   * syslog pipe, which implies that all other backends have exited
   * (including the postmaster).
   */
  wes = CreateWaitEventSet(NULL, 2);
  AddWaitEventToSet(wes, WL_LATCH_SET, PGINVALID_SOCKET, MyLatch, NULL);
#ifndef WIN32
  AddWaitEventToSet(wes, WL_SOCKET_READABLE, syslogPipe[0], NULL, NULL);
#endif

  /* main worker loop */
  for (;;)
  {
    bool    time_based_rotation = false;
    int     size_rotation_for = 0;
    long    cur_timeout;
    WaitEvent event;

#ifndef WIN32
    int     rc;
#endif

    /* Clear any already-pending wakeups */
    ResetLatch(MyLatch);

    /*
     * Process any requests or signals received recently.
     */
    if (ConfigReloadPending)
    {
      ConfigReloadPending = false;
      ProcessConfigFile(PGC_SIGHUP);

      /*
       * Check if the log directory or filename pattern changed in
       * postgresql.conf. If so, force rotation to make sure we're
       * writing the logfiles in the right place.
       */
      if (strcmp(Log_directory, currentLogDir) != 0)
      {
        pfree(currentLogDir);
        currentLogDir = pstrdup(Log_directory);
        rotation_requested = true;

        /*
         * Also, create new directory if not present; ignore errors
         */
        (void) MakePGDirectory(Log_directory);
      }
      if (strcmp(Log_filename, currentLogFilename) != 0)
      {
        pfree(currentLogFilename);
        currentLogFilename = pstrdup(Log_filename);
        rotation_requested = true;
      }

      /*
       * Force a rotation if CSVLOG output was just turned on or off and
       * we need to open or close csvlogFile accordingly.
       */
      if (((Log_destination & LOG_DESTINATION_CSVLOG) != 0) !=
        (csvlogFile != NULL))
        rotation_requested = true;

      /*
       * Force a rotation if JSONLOG output was just turned on or off
       * and we need to open or close jsonlogFile accordingly.
       */
      if (((Log_destination & LOG_DESTINATION_JSONLOG) != 0) !=
        (jsonlogFile != NULL))
        rotation_requested = true;

      /*
       * If rotation time parameter changed, reset next rotation time,
       * but don't immediately force a rotation.
       */
      if (currentLogRotationAge != Log_RotationAge)
      {
        currentLogRotationAge = Log_RotationAge;
        set_next_rotation_time();
      }

      /*
       * If we had a rotation-disabling failure, re-enable rotation
       * attempts after SIGHUP, and force one immediately.
       */
      if (rotation_disabled)
      {
        rotation_disabled = false;
        rotation_requested = true;
      }

      /*
       * Force rewriting last log filename when reloading configuration.
       * Even if rotation_requested is false, log_destination may have
       * been changed and we don't want to wait the next file rotation.
       */
      update_metainfo_datafile();
    }

    if (Log_RotationAge > 0 && !rotation_disabled)
    {
      /* Do a logfile rotation if it's time */
      now = (pg_time_t) time(NULL);
      if (now >= next_rotation_time)
        rotation_requested = time_based_rotation = true;
    }

    if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
    {
      /* Do a rotation if file is too big */
      if (ftello(syslogFile) >= Log_RotationSize * (pgoff_t) 1024)
      {
        rotation_requested = true;
        size_rotation_for |= LOG_DESTINATION_STDERR;
      }
      if (csvlogFile != NULL &&
        ftello(csvlogFile) >= Log_RotationSize * (pgoff_t) 1024)
      {
        rotation_requested = true;
        size_rotation_for |= LOG_DESTINATION_CSVLOG;
      }
      if (jsonlogFile != NULL &&
        ftello(jsonlogFile) >= Log_RotationSize * (pgoff_t) 1024)
      {
        rotation_requested = true;
        size_rotation_for |= LOG_DESTINATION_JSONLOG;
      }
    }

    if (rotation_requested)
    {
      /*
       * Force rotation when both values are zero. It means the request
       * was sent by pg_rotate_logfile() or "pg_ctl logrotate".
       */
      if (!time_based_rotation && size_rotation_for == 0)
        size_rotation_for = LOG_DESTINATION_STDERR |
          LOG_DESTINATION_CSVLOG |
          LOG_DESTINATION_JSONLOG;
      logfile_rotate(time_based_rotation, size_rotation_for);
    }

    /*
     * Calculate time till next time-based rotation, so that we don't
     * sleep longer than that.  We assume the value of "now" obtained
     * above is still close enough.  Note we can't make this calculation
     * until after calling logfile_rotate(), since it will advance
     * next_rotation_time.
     *
     * Also note that we need to beware of overflow in calculation of the
     * timeout: with large settings of Log_RotationAge, next_rotation_time
     * could be more than INT_MAX msec in the future.  In that case we'll
     * wait no more than INT_MAX msec, and try again.
     */
    if (Log_RotationAge > 0 && !rotation_disabled)
    {
      pg_time_t delay;

      delay = next_rotation_time - now;
      if (delay > 0)
      {
        if (delay > INT_MAX / 1000)
          delay = INT_MAX / 1000;
        cur_timeout = delay * 1000L;  /* msec */
      }
      else
        cur_timeout = 0;
    }
    else
      cur_timeout = -1L;

    /*
     * Sleep until there's something to do
     */
#ifndef WIN32
    rc = WaitEventSetWait(wes, cur_timeout, &event, 1,
                WAIT_EVENT_SYSLOGGER_MAIN);

    if (rc == 1 && event.events == WL_SOCKET_READABLE)
    {
      ssize_t   bytesRead;

      bytesRead = read(syslogPipe[0],
               logbuffer + bytes_in_logbuffer,
               sizeof(logbuffer) - bytes_in_logbuffer);
      if (bytesRead < 0)
      {
        if (errno != EINTR)
          ereport(LOG,
              (errcode_for_socket_access(),
               errmsg("could not read from logger pipe: %m")));
      }
      else if (bytesRead > 0)
      {
        bytes_in_logbuffer += bytesRead;
        process_pipe_input(logbuffer, &bytes_in_logbuffer);
        continue;
      }
      else
      {
        /*
         * Zero bytes read when select() is saying read-ready means
         * EOF on the pipe: that is, there are no longer any processes
         * with the pipe write end open.  Therefore, the postmaster
         * and all backends are shut down, and we are done.
         */
        pipe_eof_seen = true;

        /* if there's any data left then force it out now */
        flush_pipe_input(logbuffer, &bytes_in_logbuffer);
      }
    }
#else             /* WIN32 */

    /*
     * On Windows we leave it to a separate thread to transfer data and
     * detect pipe EOF.  The main thread just wakes up to handle SIGHUP
     * and rotation conditions.
     *
     * Server code isn't generally thread-safe, so we ensure that only one
     * of the threads is active at a time by entering the critical section
     * whenever we're not sleeping.
     */
    LeaveCriticalSection(&sysloggerSection);

    (void) WaitEventSetWait(wes, cur_timeout, &event, 1,
                WAIT_EVENT_SYSLOGGER_MAIN);

    EnterCriticalSection(&sysloggerSection);
#endif              /* WIN32 */

    if (pipe_eof_seen)
    {
      /*
       * seeing this message on the real stderr is annoying - so we make
       * it DEBUG1 to suppress in normal use.
       */
      ereport(DEBUG1,
          (errmsg_internal("logger shutting down")));

      /*
       * Normal exit from the syslogger is here.  Note that we
       * deliberately do not close syslogFile before exiting; this is to
       * allow for the possibility of elog messages being generated
       * inside proc_exit.  Regular exit() will take care of flushing
       * and closing stdio channels.
       */
      proc_exit(0);
    }
  }
}

/*
 * Postmaster subroutine to start a syslogger subprocess.
 */
int
SysLogger_Start(int child_slot)
{
  pid_t   sysloggerPid;
  char     *filename;
#ifdef EXEC_BACKEND
  SysloggerStartupData startup_data;
#endif              /* EXEC_BACKEND */

  Assert(Logging_collector);

  /*
   * If first time through, create the pipe which will receive stderr
   * output.
   *
   * If the syslogger crashes and needs to be restarted, we continue to use
   * the same pipe (indeed must do so, since extant backends will be writing
   * into that pipe).
   *
   * This means the postmaster must continue to hold the read end of the
   * pipe open, so we can pass it down to the reincarnated syslogger. This
   * is a bit klugy but we have little choice.
   *
   * Also note that we don't bother counting the pipe FDs by calling
   * Reserve/ReleaseExternalFD.  There's no real need to account for them
   * accurately in the postmaster or syslogger process, and both ends of the
   * pipe will wind up closed in all other postmaster children.
   */
#ifndef WIN32
  if (syslogPipe[0] < 0)
  {
    if (pipe(syslogPipe) < 0)
      ereport(FATAL,
          (errcode_for_socket_access(),
           errmsg("could not create pipe for syslog: %m")));
  }
#else
  if (!syslogPipe[0])
  {
    SECURITY_ATTRIBUTES sa;

    memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
    sa.nLength = sizeof(SECURITY_ATTRIBUTES);
    sa.bInheritHandle = TRUE;

    if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
      ereport(FATAL,
          (errcode_for_file_access(),
           errmsg("could not create pipe for syslog: %m")));
  }
#endif

  /*
   * Create log directory if not present; ignore errors
   */
  (void) MakePGDirectory(Log_directory);

  /*
   * The initial logfile is created right in the postmaster, to verify that
   * the Log_directory is writable.  We save the reference time so that the
   * syslogger child process can recompute this file name.
   *
   * It might look a bit strange to re-do this during a syslogger restart,
   * but we must do so since the postmaster closed syslogFile after the
   * previous fork (and remembering that old file wouldn't be right anyway).
   * Note we always append here, we won't overwrite any existing file.  This
   * is consistent with the normal rules, because by definition this is not
   * a time-based rotation.
   */
  first_syslogger_file_time = time(NULL);

  filename = logfile_getname(first_syslogger_file_time, NULL);

  syslogFile = logfile_open(filename, "a", false);

  pfree(filename);

  /*
   * Likewise for the initial CSV log file, if that's enabled.  (Note that
   * we open syslogFile even when only CSV output is nominally enabled,
   * since some code paths will write to syslogFile anyway.)
   */
  if (Log_destination & LOG_DESTINATION_CSVLOG)
  {
    filename = logfile_getname(first_syslogger_file_time, ".csv");

    csvlogFile = logfile_open(filename, "a", false);

    pfree(filename);
  }

  /*
   * Likewise for the initial JSON log file, if that's enabled.  (Note that
   * we open syslogFile even when only JSON output is nominally enabled,
   * since some code paths will write to syslogFile anyway.)
   */
  if (Log_destination & LOG_DESTINATION_JSONLOG)
  {
    filename = logfile_getname(first_syslogger_file_time, ".json");

    jsonlogFile = logfile_open(filename, "a", false);

    pfree(filename);
  }

#ifdef EXEC_BACKEND
  startup_data.syslogFile = syslogger_fdget(syslogFile);
  startup_data.csvlogFile = syslogger_fdget(csvlogFile);
  startup_data.jsonlogFile = syslogger_fdget(jsonlogFile);
  sysloggerPid = postmaster_child_launch(B_LOGGER, child_slot,
                       &startup_data, sizeof(startup_data), NULL);
#else
  sysloggerPid = postmaster_child_launch(B_LOGGER, child_slot,
                       NULL, 0, NULL);
#endif              /* EXEC_BACKEND */

  if (sysloggerPid == -1)
  {
    ereport(LOG,
        (errmsg("could not fork system logger: %m")));
    return 0;
  }

  /* success, in postmaster */

  /* now we redirect stderr, if not done already */
  if (!redirection_done)
  {
#ifdef WIN32
    int     fd;
#endif

    /*
     * Leave a breadcrumb trail when redirecting, in case the user forgets
     * that redirection is active and looks only at the original stderr
     * target file.
     */
    ereport(LOG,
        (errmsg("redirecting log output to logging collector process"),
         errhint("Future log output will appear in directory \"%s\".",
             Log_directory)));

#ifndef WIN32
    fflush(stdout);
    if (dup2(syslogPipe[1], STDOUT_FILENO) < 0)
      ereport(FATAL,
          (errcode_for_file_access(),
           errmsg("could not redirect stdout: %m")));
    fflush(stderr);
    if (dup2(syslogPipe[1], STDERR_FILENO) < 0)
      ereport(FATAL,
          (errcode_for_file_access(),
           errmsg("could not redirect stderr: %m")));
    /* Now we are done with the write end of the pipe. */
    close(syslogPipe[1]);
    syslogPipe[1] = -1;
#else

    /*
     * open the pipe in binary mode and make sure stderr is binary after
     * it's been dup'ed into, to avoid disturbing the pipe chunking
     * protocol.
     */
    fflush(stderr);
    fd = _open_osfhandle((intptr_t) syslogPipe[1],
               _O_APPEND | _O_BINARY);
    if (dup2(fd, STDERR_FILENO) < 0)
      ereport(FATAL,
          (errcode_for_file_access(),
           errmsg("could not redirect stderr: %m")));
    close(fd);
    _setmode(STDERR_FILENO, _O_BINARY);

    /*
     * Now we are done with the write end of the pipe.  CloseHandle() must
     * not be called because the preceding close() closes the underlying
     * handle.
     */
    syslogPipe[1] = 0;
#endif
    redirection_done = true;
  }

  /* postmaster will never write the file(s); close 'em */
  fclose(syslogFile);
  syslogFile = NULL;
  if (csvlogFile != NULL)
  {
    fclose(csvlogFile);
    csvlogFile = NULL;
  }
  if (jsonlogFile != NULL)
  {
    fclose(jsonlogFile);
    jsonlogFile = NULL;
  }
  return (int) sysloggerPid;
}


#ifdef EXEC_BACKEND

/*
 * syslogger_fdget() -
 *
 * Utility wrapper to grab the file descriptor of an opened error output
 * file.  Used when building the command to fork the logging collector.
 */
static int
syslogger_fdget(FILE *file)
{
#ifndef WIN32
  if (file != NULL)
    return fileno(file);
  else
    return -1;
#else
  if (file != NULL)
    return (int) _get_osfhandle(_fileno(file));
  else
    return 0;
#endif              /* WIN32 */
}

/*
 * syslogger_fdopen() -
 *
 * Utility wrapper to re-open an error output file, using the given file
 * descriptor.  Used when parsing arguments in a forked logging collector.
 */
static FILE *
syslogger_fdopen(int fd)
{
  FILE     *file = NULL;

#ifndef WIN32
  if (fd != -1)
  {
    file = fdopen(fd, "a");
    setvbuf(file, NULL, PG_IOLBF, 0);
  }
#else             /* WIN32 */
  if (fd != 0)
  {
    fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
    if (fd > 0)
    {
      file = fdopen(fd, "a");
      setvbuf(file, NULL, PG_IOLBF, 0);
    }
  }
#endif              /* WIN32 */

  return file;
}
#endif              /* EXEC_BACKEND */


/* --------------------------------
 *    pipe protocol handling
 * --------------------------------
 */

/*
 * Process data received through the syslogger pipe.
 *
 * This routine interprets the log pipe protocol which sends log messages as
 * (hopefully atomic) chunks - such chunks are detected and reassembled here.
 *
 * The protocol has a header that starts with two nul bytes, then has a 16 bit
 * length, the pid of the sending process, and a flag to indicate if it is
 * the last chunk in a message. Incomplete chunks are saved until we read some
 * more, and non-final chunks are accumulated until we get the final chunk.
 *
 * All of this is to avoid 2 problems:
 * . partial messages being written to logfiles (messes rotation), and
 * . messages from different backends being interleaved (messages garbled).
 *
 * Any non-protocol messages are written out directly. These should only come
 * from non-PostgreSQL sources, however (e.g. third party libraries writing to
 * stderr).
 *
 * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
 * of bytes present.  On exit, any not-yet-eaten data is left-justified in
 * logbuffer, and *bytes_in_logbuffer is updated.
 */
static void
process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
{
  char     *cursor = logbuffer;
  int     count = *bytes_in_logbuffer;
  int     dest = LOG_DESTINATION_STDERR;

  /* While we have enough for a header, process data... */
  while (count >= (int) (offsetof(PipeProtoHeader, data) + 1))
  {
    PipeProtoHeader p;
    int     chunklen;
    uint8   dest_flags;

    /* Do we have a valid header? */
    memcpy(&p, cursor, offsetof(PipeProtoHeader, data));
    dest_flags = p.flags & (PIPE_PROTO_DEST_STDERR |
                PIPE_PROTO_DEST_CSVLOG |
                PIPE_PROTO_DEST_JSONLOG);
    if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
      p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
      p.pid != 0 &&
      pg_number_of_ones[dest_flags] == 1)
    {
      List     *buffer_list;
      ListCell   *cell;
      save_buffer *existing_slot = NULL,
             *free_slot = NULL;
      StringInfo  str;

      chunklen = PIPE_HEADER_SIZE + p.len;

      /* Fall out of loop if we don't have the whole chunk yet */
      if (count < chunklen)
        break;

      if ((p.flags & PIPE_PROTO_DEST_STDERR) != 0)
        dest = LOG_DESTINATION_STDERR;
      else if ((p.flags & PIPE_PROTO_DEST_CSVLOG) != 0)
        dest = LOG_DESTINATION_CSVLOG;
      else if ((p.flags & PIPE_PROTO_DEST_JSONLOG) != 0)
        dest = LOG_DESTINATION_JSONLOG;
      else
      {
        /* this should never happen as of the header validation */
        Assert(false);
      }

      /* Locate any existing buffer for this source pid */
      buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
      foreach(cell, buffer_list)
      {
        save_buffer *buf = (save_buffer *) lfirst(cell);

        if (buf->pid == p.pid)
        {
          existing_slot = buf;
          break;
        }
        if (buf->pid == 0 && free_slot == NULL)
          free_slot = buf;
      }

      if ((p.flags & PIPE_PROTO_IS_LAST) == 0)
      {
        /*
         * Save a complete non-final chunk in a per-pid buffer
         */
        if (existing_slot != NULL)
        {
          /* Add chunk to data from preceding chunks */
          str = &(existing_slot->data);
          appendBinaryStringInfo(str,
                       cursor + PIPE_HEADER_SIZE,
                       p.len);
        }
        else
        {
          /* First chunk of message, save in a new buffer */
          if (free_slot == NULL)
          {
            /*
             * Need a free slot, but there isn't one in the list,
             * so create a new one and extend the list with it.
             */
            free_slot = palloc_object(save_buffer);
            buffer_list = lappend(buffer_list, free_slot);
            buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
          }
          free_slot->pid = p.pid;
          str = &(free_slot->data);
          initStringInfo(str);
          appendBinaryStringInfo(str,
                       cursor + PIPE_HEADER_SIZE,
                       p.len);
        }
      }
      else
      {
        /*
         * Final chunk --- add it to anything saved for that pid, and
         * either way write the whole thing out.
         */
        if (existing_slot != NULL)
        {
          str = &(existing_slot->data);
          appendBinaryStringInfo(str,
                       cursor + PIPE_HEADER_SIZE,
                       p.len);
          write_syslogger_file(str->data, str->len, dest);
          /* Mark the buffer unused, and reclaim string storage */
          existing_slot->pid = 0;
          pfree(str->data);
        }
        else
        {
          /* The whole message was one chunk, evidently. */
          write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
                     dest);
        }
      }

      /* Finished processing this chunk */
      cursor += chunklen;
      count -= chunklen;
    }
    else
    {
      /* Process non-protocol data */

      /*
       * Look for the start of a protocol header.  If found, dump data
       * up to there and repeat the loop.  Otherwise, dump it all and
       * fall out of the loop.  (Note: we want to dump it all if at all
       * possible, so as to avoid dividing non-protocol messages across
       * logfiles.  We expect that in many scenarios, a non-protocol
       * message will arrive all in one read(), and we want to respect
       * the read() boundary if possible.)
       */
      for (chunklen = 1; chunklen < count; chunklen++)
      {
        if (cursor[chunklen] == '\0')
          break;
      }
      /* fall back on the stderr log as the destination */
      write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
      cursor += chunklen;
      count -= chunklen;
    }
  }

  /* We don't have a full chunk, so left-align what remains in the buffer */
  if (count > 0 && cursor != logbuffer)
    memmove(logbuffer, cursor, count);
  *bytes_in_logbuffer = count;
}

/*
 * Force out any buffered data
 *
 * This is currently used only at syslogger shutdown, but could perhaps be
 * useful at other times, so it is careful to leave things in a clean state.
 */
static void
flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
{
  int     i;

  /* Dump any incomplete protocol messages */
  for (i = 0; i < NBUFFER_LISTS; i++)
  {
    List     *list = buffer_lists[i];
    ListCell   *cell;

    foreach(cell, list)
    {
      save_buffer *buf = (save_buffer *) lfirst(cell);

      if (buf->pid != 0)
      {
        StringInfo  str = &(buf->data);

        write_syslogger_file(str->data, str->len,
                   LOG_DESTINATION_STDERR);
        /* Mark the buffer unused, and reclaim string storage */
        buf->pid = 0;
        pfree(str->data);
      }
    }
  }

  /*
   * Force out any remaining pipe data as-is; we don't bother trying to
   * remove any protocol headers that may exist in it.
   */
  if (*bytes_in_logbuffer > 0)
    write_syslogger_file(logbuffer, *bytes_in_logbuffer,
               LOG_DESTINATION_STDERR);
  *bytes_in_logbuffer = 0;
}


/* --------------------------------
 *    logfile routines
 * --------------------------------
 */

/*
 * Write text to the currently open logfile
 *
 * This is exported so that elog.c can call it when MyBackendType is B_LOGGER.
 * This allows the syslogger process to record elog messages of its own,
 * even though its stderr does not point at the syslog pipe.
 */
void
write_syslogger_file(const char *buffer, int count, int destination)
{
  int     rc;
  FILE     *logfile;

  /*
   * If we're told to write to a structured log file, but it's not open,
   * dump the data to syslogFile (which is always open) instead.  This can
   * happen if structured output is enabled after postmaster start and we've
   * been unable to open logFile.  There are also race conditions during a
   * parameter change whereby backends might send us structured output
   * before we open the logFile or after we close it.  Writing formatted
   * output to the regular log file isn't great, but it beats dropping log
   * output on the floor.
   *
   * Think not to improve this by trying to open logFile on-the-fly.  Any
   * failure in that would lead to recursion.
   */
  if ((destination & LOG_DESTINATION_CSVLOG) && csvlogFile != NULL)
    logfile = csvlogFile;
  else if ((destination & LOG_DESTINATION_JSONLOG) && jsonlogFile != NULL)
    logfile = jsonlogFile;
  else
    logfile = syslogFile;

  rc = fwrite(buffer, 1, count, logfile);

  /*
   * Try to report any failure.  We mustn't use ereport because it would
   * just recurse right back here, but write_stderr is OK: it will write
   * either to the postmaster's original stderr, or to /dev/null, but never
   * to our input pipe which would result in a different sort of looping.
   */
  if (rc != count)
    write_stderr("could not write to log file: %m\n");
}

#ifdef WIN32

/*
 * Worker thread to transfer data from the pipe to the current logfile.
 *
 * We need this because on Windows, WaitForMultipleObjects does not work on
 * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
 * allow for SIGHUP; and select is for sockets only.
 */
static unsigned int __stdcall
pipeThread(void *arg)
{
  char    logbuffer[READ_BUF_SIZE];
  int     bytes_in_logbuffer = 0;

  for (;;)
  {
    DWORD   bytesRead;
    BOOL    result;

    result = ReadFile(syslogPipe[0],
              logbuffer + bytes_in_logbuffer,
              sizeof(logbuffer) - bytes_in_logbuffer,
              &bytesRead, 0);

    /*
     * Enter critical section before doing anything that might touch
     * global state shared by the main thread. Anything that uses
     * palloc()/pfree() in particular are not safe outside the critical
     * section.
     */
    EnterCriticalSection(&sysloggerSection);
    if (!result)
    {
      DWORD   error = GetLastError();

      if (error == ERROR_HANDLE_EOF ||
        error == ERROR_BROKEN_PIPE)
        break;
      _dosmaperr(error);
      ereport(LOG,
          (errcode_for_file_access(),
           errmsg("could not read from logger pipe: %m")));
    }
    else if (bytesRead > 0)
    {
      bytes_in_logbuffer += bytesRead;
      process_pipe_input(logbuffer, &bytes_in_logbuffer);
    }

    /*
     * If we've filled the current logfile, nudge the main thread to do a
     * log rotation.
     */
    if (Log_RotationSize > 0)
    {
      if (ftello(syslogFile) >= Log_RotationSize * (pgoff_t) 1024 ||
        (csvlogFile != NULL &&
         ftello(csvlogFile) >= Log_RotationSize * (pgoff_t) 1024) ||
        (jsonlogFile != NULL &&
         ftello(jsonlogFile) >= Log_RotationSize * (pgoff_t) 1024))
        SetLatch(MyLatch);
    }
    LeaveCriticalSection(&sysloggerSection);
  }

  /* We exit the above loop only upon detecting pipe EOF */
  pipe_eof_seen = true;

  /* if there's any data left then force it out now */
  flush_pipe_input(logbuffer, &bytes_in_logbuffer);

  /* set the latch to waken the main thread, which will quit */
  SetLatch(MyLatch);

  LeaveCriticalSection(&sysloggerSection);
  _endthread();
  return 0;
}
#endif              /* WIN32 */

/*
 * Open a new logfile with proper permissions and buffering options.
 *
 * If allow_errors is true, we just log any open failure and return NULL
 * (with errno still correct for the fopen failure).
 * Otherwise, errors are treated as fatal.
 */
static FILE *
logfile_open(const char *filename, const char *mode, bool allow_errors)
{
  FILE     *fh;
  mode_t    oumask;

  /*
   * Note we do not let Log_file_mode disable IWUSR, since we certainly want
   * to be able to write the files ourselves.
   */
  oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
  fh = fopen(filename, mode);
  umask(oumask);

  if (fh)
  {
    setvbuf(fh, NULL, PG_IOLBF, 0);

#ifdef WIN32
    /* use CRLF line endings on Windows */
    _setmode(_fileno(fh), _O_TEXT);
#endif
  }
  else
  {
    int     save_errno = errno;

    ereport(allow_errors ? LOG : FATAL,
        (errcode_for_file_access(),
         errmsg("could not open log file \"%s\": %m",
            filename)));
    errno = save_errno;
  }

  return fh;
}

/*
 * Do logfile rotation for a single destination, as specified by target_dest.
 * The information stored in *last_file_name and *logFile is updated on a
 * successful file rotation.
 *
 * Returns false if the rotation has been stopped, or true to move on to
 * the processing of other formats.
 */
static bool
logfile_rotate_dest(bool time_based_rotation, int size_rotation_for,
          pg_time_t fntime, int target_dest,
          char **last_file_name, FILE **logFile)
{
  char     *logFileExt = NULL;
  char     *filename;
  FILE     *fh;

  /*
   * If the target destination was just turned off, close the previous file
   * and unregister its data.  This cannot happen for stderr as syslogFile
   * is assumed to be always opened even if stderr is disabled in
   * log_destination.
   */
  if ((Log_destination & target_dest) == 0 &&
    target_dest != LOG_DESTINATION_STDERR)
  {
    if (*logFile != NULL)
      fclose(*logFile);
    *logFile = NULL;
    if (*last_file_name != NULL)
      pfree(*last_file_name);
    *last_file_name = NULL;
    return true;
  }

  /*
   * Leave if it is not time for a rotation or if the target destination has
   * no need to do a rotation based on the size of its file.
   */
  if (!time_based_rotation && (size_rotation_for & target_dest) == 0)
    return true;

  /* file extension depends on the destination type */
  if (target_dest == LOG_DESTINATION_STDERR)
    logFileExt = NULL;
  else if (target_dest == LOG_DESTINATION_CSVLOG)
    logFileExt = ".csv";
  else if (target_dest == LOG_DESTINATION_JSONLOG)
    logFileExt = ".json";
  else
  {
    /* cannot happen */
    Assert(false);
  }

  /* build the new file name */
  filename = logfile_getname(fntime, logFileExt);

  /*
   * Decide whether to overwrite or append.  We can overwrite if (a)
   * Log_truncate_on_rotation is set, (b) the rotation was triggered by
   * elapsed time and not something else, and (c) the computed file name is
   * different from what we were previously logging into.
   */
  if (Log_truncate_on_rotation && time_based_rotation &&
    *last_file_name != NULL &&
    strcmp(filename, *last_file_name) != 0)
    fh = logfile_open(filename, "w", true);
  else
    fh = logfile_open(filename, "a", true);

  if (!fh)
  {
    /*
     * ENFILE/EMFILE are not too surprising on a busy system; just keep
     * using the old file till we manage to get a new one.  Otherwise,
     * assume something's wrong with Log_directory and stop trying to
     * create files.
     */
    if (errno != ENFILE && errno != EMFILE)
    {
      ereport(LOG,
          (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
      rotation_disabled = true;
    }

    if (filename)
      pfree(filename);
    return false;
  }

  /* fill in the new information */
  if (*logFile != NULL)
    fclose(*logFile);
  *logFile = fh;

  /* instead of pfree'ing filename, remember it for next time */
  if (*last_file_name != NULL)
    pfree(*last_file_name);
  *last_file_name = filename;

  return true;
}

/*
 * perform logfile rotation
 */
static void
logfile_rotate(bool time_based_rotation, int size_rotation_for)
{
  pg_time_t fntime;

  rotation_requested = false;

  /*
   * When doing a time-based rotation, invent the new logfile name based on
   * the planned rotation time, not current time, to avoid "slippage" in the
   * file name when we don't do the rotation immediately.
   */
  if (time_based_rotation)
    fntime = next_rotation_time;
  else
    fntime = time(NULL);

  /* file rotation for stderr */
  if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
               LOG_DESTINATION_STDERR, &last_sys_file_name,
               &syslogFile))
    return;

  /* file rotation for csvlog */
  if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
               LOG_DESTINATION_CSVLOG, &last_csv_file_name,
               &csvlogFile))
    return;

  /* file rotation for jsonlog */
  if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
               LOG_DESTINATION_JSONLOG, &last_json_file_name,
               &jsonlogFile))
    return;

  update_metainfo_datafile();

  set_next_rotation_time();
}


/*
 * construct logfile name using timestamp information
 *
 * If suffix isn't NULL, append it to the name, replacing any ".log"
 * that may be in the pattern.
 *
 * Result is palloc'd.
 */
static char *
logfile_getname(pg_time_t timestamp, const char *suffix)
{
  char     *filename;
  int     len;

  filename = palloc(MAXPGPATH);

  snprintf(filename, MAXPGPATH, "%s/", Log_directory);

  len = strlen(filename);

  /* treat Log_filename as a strftime pattern */
  pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
        pg_localtime(&timestamp, log_timezone));

  if (suffix != NULL)
  {
    len = strlen(filename);
    if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
      len -= 4;
    strlcpy(filename + len, suffix, MAXPGPATH - len);
  }

  return filename;
}

/*
 * Determine the next planned rotation time, and store in next_rotation_time.
 */
static void
set_next_rotation_time(void)
{
  pg_time_t now;
  struct pg_tm *tm;
  int     rotinterval;

  /* nothing to do if time-based rotation is disabled */
  if (Log_RotationAge <= 0)
    return;

  /*
   * The requirements here are to choose the next time > now that is a
   * "multiple" of the log rotation interval.  "Multiple" can be interpreted
   * fairly loosely.  In this version we align to log_timezone rather than
   * GMT.
   */
  rotinterval = Log_RotationAge * SECS_PER_MINUTE; /* convert to seconds */
  now = (pg_time_t) time(NULL);
  tm = pg_localtime(&now, log_timezone);
  now += tm->tm_gmtoff;
  now -= now % rotinterval;
  now += rotinterval;
  now -= tm->tm_gmtoff;
  next_rotation_time = now;
}

/*
 * Store the name of the file(s) where the log collector, when enabled, writes
 * log messages.  Useful for finding the name(s) of the current log file(s)
 * when there is time-based logfile rotation.  Filenames are stored in a
 * temporary file and which is renamed into the final destination for
 * atomicity.  The file is opened with the same permissions as what gets
 * created in the data directory and has proper buffering options.
 */
static void
update_metainfo_datafile(void)
{
  FILE     *fh;
  mode_t    oumask;

  if (!(Log_destination & LOG_DESTINATION_STDERR) &&
    !(Log_destination & LOG_DESTINATION_CSVLOG) &&
    !(Log_destination & LOG_DESTINATION_JSONLOG))
  {
    if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
      ereport(LOG,
          (errcode_for_file_access(),
           errmsg("could not remove file \"%s\": %m",
              LOG_METAINFO_DATAFILE)));
    return;
  }

  /* use the same permissions as the data directory for the new file */
  oumask = umask(pg_mode_mask);
  fh = fopen(LOG_METAINFO_DATAFILE_TMP, "w");
  umask(oumask);

  if (fh)
  {
    setvbuf(fh, NULL, PG_IOLBF, 0);

#ifdef WIN32
    /* use CRLF line endings on Windows */
    _setmode(_fileno(fh), _O_TEXT);
#endif
  }
  else
  {
    ereport(LOG,
        (errcode_for_file_access(),
         errmsg("could not open file \"%s\": %m",
            LOG_METAINFO_DATAFILE_TMP)));
    return;
  }

  if (last_sys_file_name && (Log_destination & LOG_DESTINATION_STDERR))
  {
    if (fprintf(fh, "stderr %s\n", last_sys_file_name) < 0)
    {
      ereport(LOG,
          (errcode_for_file_access(),
           errmsg("could not write file \"%s\": %m",
              LOG_METAINFO_DATAFILE_TMP)));
      fclose(fh);
      return;
    }
  }

  if (last_csv_file_name && (Log_destination & LOG_DESTINATION_CSVLOG))
  {
    if (fprintf(fh, "csvlog %s\n", last_csv_file_name) < 0)
    {
      ereport(LOG,
          (errcode_for_file_access(),
           errmsg("could not write file \"%s\": %m",
              LOG_METAINFO_DATAFILE_TMP)));
      fclose(fh);
      return;
    }
  }

  if (last_json_file_name && (Log_destination & LOG_DESTINATION_JSONLOG))
  {
    if (fprintf(fh, "jsonlog %s\n", last_json_file_name) < 0)
    {
      ereport(LOG,
          (errcode_for_file_access(),
           errmsg("could not write file \"%s\": %m",
              LOG_METAINFO_DATAFILE_TMP)));
      fclose(fh);
      return;
    }
  }
  fclose(fh);

  if (rename(LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE) != 0)
    ereport(LOG,
        (errcode_for_file_access(),
         errmsg("could not rename file \"%s\" to \"%s\": %m",
            LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE)));
}

/* --------------------------------
 *    signal handler routines
 * --------------------------------
 */

/*
 * Check to see if a log rotation request has arrived.  Should be
 * called by postmaster after receiving SIGUSR1.
 */
bool
CheckLogrotateSignal(void)
{
  struct stat stat_buf;

  if (stat(LOGROTATE_SIGNAL_FILE, &stat_buf) == 0)
    return true;

  return false;
}

/*
 * Remove the file signaling a log rotation request.
 */
void
RemoveLogrotateSignalFiles(void)
{
  unlink(LOGROTATE_SIGNAL_FILE);
}

/* SIGUSR1: set flag to rotate logfile */
static void
sigUsr1Handler(SIGNAL_ARGS)
{
  rotation_requested = true;
  SetLatch(MyLatch);
}

Coverage Report

Created: 2026-08-14 06:37