Latch-ifying the syslogger process

Поиск
Список
Период
Сортировка
От Tom Lane
Тема Latch-ifying the syslogger process
Дата
Msg-id 11274.1336851393@sss.pgh.pa.us
обсуждение исходный текст
Ответы Re: Latch-ifying the syslogger process  (Andrew Dunstan <andrew@dunslane.net>)
Re: Latch-ifying the syslogger process  (Tom Lane <tgl@sss.pgh.pa.us>)
Список pgsql-hackers
I noticed a large oversight in our efforts to reduce the server's idle
wakeup frequency: if you've got logging_collector turned on, the
syslogger process will wake up once a second, whether it has anything
to do or not.  But the only reasons it has for waking up are signals,
data arrival, and time-based logfile rotation, and it is easy to
calculate the time until the next logfile rotation event.  So this
seems really easy to latch-ify, and I would like to apply the attached
patch if there are not objections.  I do not however have the ability
to test the Windows side of it, so it'd be nice if someone would check
that that still works (particularly, that it shuts down cleanly).

While testing this I discovered a pre-existing bug in the Unix
implementation of WaitLatchOrSocket: EOF on the socket is reported as
POLLHUP not POLLIN (at least on my Linux box), which results in
WaitLatchOrSocket going into an infinite loop, because poll() returns
immediately but the result bitmask never becomes nonzero.  So at least
the first hunk of this patch had better get applied and back-patched
in any case.

            regards, tom lane

diff --git a/src/backend/port/unix_latch.c b/src/backend/port/unix_latch.c
index 30d1a48..de0af87 100644
*** a/src/backend/port/unix_latch.c
--- b/src/backend/port/unix_latch.c
*************** WaitLatchOrSocket(volatile Latch *latch,
*** 293,299 ****
              result |= WL_TIMEOUT;
          }
          if ((wakeEvents & WL_SOCKET_READABLE) &&
!             (pfds[0].revents & POLLIN))
          {
              /* data available in socket */
              result |= WL_SOCKET_READABLE;
--- 293,299 ----
              result |= WL_TIMEOUT;
          }
          if ((wakeEvents & WL_SOCKET_READABLE) &&
!             (pfds[0].revents & (POLLIN | POLLHUP | POLLERR)))
          {
              /* data available in socket */
              result |= WL_SOCKET_READABLE;
diff --git a/src/backend/postmaster/syslogger.c b/src/backend/postmaster/syslogger.c
index f5ae841..3528879 100644
*** a/src/backend/postmaster/syslogger.c
--- b/src/backend/postmaster/syslogger.c
***************
*** 9,16 ****
   * 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 an internal naming scheme that mangles
!  * creation time and current postmaster pid.
   *
   * Author: Andreas Pflug <pgadmin@pse-consulting.de>
   *
--- 9,15 ----
   * 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>
   *
***************
*** 40,45 ****
--- 39,45 ----
  #include "postmaster/postmaster.h"
  #include "postmaster/syslogger.h"
  #include "storage/ipc.h"
+ #include "storage/latch.h"
  #include "storage/pg_shmem.h"
  #include "utils/guc.h"
  #include "utils/ps_status.h"
*************** static FILE *syslogFile = NULL;
*** 93,98 ****
--- 93,99 ----
  static FILE *csvlogFile = NULL;
  static char *last_file_name = NULL;
  static char *last_csv_file_name = NULL;
+ static Latch sysLoggerLatch;

  /*
   * Buffers for saving partial messages from different backends.
*************** SysLoggerMain(int argc, char *argv[])
*** 168,179 ****
--- 169,182 ----
      char       *currentLogDir;
      char       *currentLogFilename;
      int            currentLogRotationAge;
+     pg_time_t    now;

      IsUnderPostmaster = true;    /* we are a postmaster subprocess now */

      MyProcPid = getpid();        /* reset MyProcPid */

      MyStartTime = time(NULL);    /* set our start time in case we call elog */
+     now = MyStartTime;

  #ifdef EXEC_BACKEND
      syslogger_parseArgs(argc, argv);
*************** SysLoggerMain(int argc, char *argv[])
*** 246,251 ****
--- 249,257 ----
          elog(FATAL, "setsid() failed: %m");
  #endif

+     /* Initialize private latch for use by signal handlers */
+     InitLatch(&sysLoggerLatch);
+
      /*
       * Properly accept or ignore signals the postmaster might send us
       *
*************** SysLoggerMain(int argc, char *argv[])
*** 296,309 ****
      {
          bool        time_based_rotation = false;
          int            size_rotation_for = 0;

  #ifndef WIN32
-         int            bytesRead;
          int            rc;
-         fd_set        rfds;
-         struct timeval timeout;
  #endif

          if (got_SIGHUP)
          {
              got_SIGHUP = false;
--- 302,320 ----
      {
          bool        time_based_rotation = false;
          int            size_rotation_for = 0;
+         long        cur_timeout;
+         int            cur_flags;

  #ifndef WIN32
          int            rc;
  #endif

+         /* Clear any already-pending wakeups */
+         ResetLatch(&sysLoggerLatch);
+
+         /*
+          * Process any requests or signals received recently.
+          */
          if (got_SIGHUP)
          {
              got_SIGHUP = false;
*************** SysLoggerMain(int argc, char *argv[])
*** 353,363 ****
              }
          }

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

!         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;
          }
*************** SysLoggerMain(int argc, char *argv[])
*** 389,416 ****
              logfile_rotate(time_based_rotation, size_rotation_for);
          }

- #ifndef WIN32
-
          /*
!          * Wait for some data, timing out after 1 second
           */
!         FD_ZERO(&rfds);
!         FD_SET(syslogPipe[0], &rfds);
!
!         timeout.tv_sec = 1;
!         timeout.tv_usec = 0;
!
!         rc = select(syslogPipe[0] + 1, &rfds, NULL, NULL, &timeout);
!
!         if (rc < 0)
          {
!             if (errno != EINTR)
!                 ereport(LOG,
!                         (errcode_for_socket_access(),
!                          errmsg("select() failed in logger process: %m")));
          }
!         else if (rc > 0 && FD_ISSET(syslogPipe[0], &rfds))
          {
              bytesRead = read(syslogPipe[0],
                               logbuffer + bytes_in_logbuffer,
                               sizeof(logbuffer) - bytes_in_logbuffer);
--- 399,438 ----
              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.
           */
!         if (Log_RotationAge > 0 && !rotation_disabled)
          {
!             if (now < next_rotation_time)
!                 cur_timeout = (next_rotation_time - now) * 1000L; /* msec */
!             else
!                 cur_timeout = 0;
!             cur_flags = WL_TIMEOUT;
          }
!         else
!         {
!             cur_timeout = -1L;
!             cur_flags = 0;
!         }
!
!         /*
!          * Sleep until there's something to do
!          */
! #ifndef WIN32
!         rc = WaitLatchOrSocket(&sysLoggerLatch,
!                                WL_LATCH_SET | WL_SOCKET_READABLE | cur_flags,
!                                syslogPipe[0],
!                                cur_timeout);
!
!         if (rc & WL_SOCKET_READABLE)
          {
+             int            bytesRead;
+
              bytesRead = read(syslogPipe[0],
                               logbuffer + bytes_in_logbuffer,
                               sizeof(logbuffer) - bytes_in_logbuffer);
*************** SysLoggerMain(int argc, char *argv[])
*** 445,452 ****

          /*
           * On Windows we leave it to a separate thread to transfer data and
!          * detect pipe EOF.  The main thread just wakes up once a second to
!          * check for 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
--- 467,474 ----

          /*
           * 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
*************** SysLoggerMain(int argc, char *argv[])
*** 454,460 ****
           */
          LeaveCriticalSection(&sysloggerSection);

!         pg_usleep(1000000L);

          EnterCriticalSection(&sysloggerSection);
  #endif   /* WIN32 */
--- 476,484 ----
           */
          LeaveCriticalSection(&sysloggerSection);

!         (void) WaitLatch(&sysLoggerLatch,
!                          WL_LATCH_SET | cur_flags,
!                          cur_timeout);

          EnterCriticalSection(&sysloggerSection);
  #endif   /* WIN32 */
*************** write_syslogger_file(const char *buffer,
*** 957,963 ****
  /*
   * Worker thread to transfer data from the pipe to the current logfile.
   *
!  * We need this because on Windows, WaitForSingleObject 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.
   */
--- 981,987 ----
  /*
   * 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.
   */
*************** pipeThread(void *arg)
*** 1010,1015 ****
--- 1034,1042 ----
      /* 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(&sysLoggerLatch);
+
      LeaveCriticalSection(&sysloggerSection);
      _endthread();
      return 0;
*************** set_next_rotation_time(void)
*** 1285,1296 ****
--- 1312,1333 ----
  static void
  sigHupHandler(SIGNAL_ARGS)
  {
+     int            save_errno = errno;
+
      got_SIGHUP = true;
+     SetLatch(&sysLoggerLatch);
+
+     errno = save_errno;
  }

  /* SIGUSR1: set flag to rotate logfile */
  static void
  sigUsr1Handler(SIGNAL_ARGS)
  {
+     int            save_errno = errno;
+
      rotation_requested = true;
+     SetLatch(&sysLoggerLatch);
+
+     errno = save_errno;
  }

В списке pgsql-hackers по дате отправления:

Предыдущее
От: Simon Riggs
Дата:
Сообщение: Re: Re: [COMMITTERS] pgsql: Ensure age() returns a stable value rather than the latest value
Следующее
От: Andrew Dunstan
Дата:
Сообщение: Re: Latch-ifying the syslogger process