Thread: WIP csv logs

WIP csv logs

From
Andrew Dunstan
Date:
Attached is my WIP version of the CSV logs patch. It does not include
docs changes.

It fixes the CSV thinko I just posted about, and also implements the
"safe to rotate" scheme I suggested yesterday, at quite a modest cost.
As Tom rightly points out, that does not protect us against interleaving
log lines from different backends, which is an open problem. It does
however protect against rotating in the middle of a log line. It also
incorporates the fix I made two days ago to remove inappropriate Windows
CRLF translation, and some code tidying.

cheers

andrew





Index: src/backend/postmaster/postmaster.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/postmaster.c,v
retrieving revision 1.527
diff -c -r1.527 postmaster.c
*** src/backend/postmaster/postmaster.c    22 Mar 2007 19:53:30 -0000    1.527
--- src/backend/postmaster/postmaster.c    6 Jun 2007 19:48:22 -0000
***************
*** 336,343 ****
--- 336,345 ----
      HANDLE        PostmasterHandle;
      HANDLE        initial_signal_pipe;
      HANDLE        syslogPipe[2];
+     HANDLE        csvlogPipe[2];
  #else
      int            syslogPipe[2];
+     int        csvlogPipe[2];
  #endif
      char        my_exec_path[MAXPGPATH];
      char        pkglib_path[MAXPGPATH];
***************
*** 1225,1231 ****
          }

          /* If we have lost the system logger, try to start a new one */
!         if (SysLoggerPID == 0 && Redirect_stderr)
              SysLoggerPID = SysLogger_Start();

          /*
--- 1227,1234 ----
          }

          /* If we have lost the system logger, try to start a new one */
!         if ( (SysLoggerPID == 0 && Redirect_stderr) ||
!              (SysLoggerPID == 0 && (Log_destination & LOG_DESTINATION_CSVLOG)) )
              SysLoggerPID = SysLogger_Start();

          /*
***************
*** 1775,1784 ****
--- 1778,1795 ----
          if (syslogPipe[0] >= 0)
              close(syslogPipe[0]);
          syslogPipe[0] = -1;
+
+         if (csvlogPipe[0] >= 0)
+             close(csvlogPipe[0]);
+         csvlogPipe[0] = -1;
  #else
          if (syslogPipe[0])
              CloseHandle(syslogPipe[0]);
          syslogPipe[0] = 0;
+
+         if (csvlogPipe[0])
+             CloseHandle(csvlogPipe[0]);
+         csvlogPipe[0] = 0;
  #endif
      }
  }
***************
*** 3957,3962 ****
--- 3968,3974 ----
  #endif

      memcpy(¶m->syslogPipe, &syslogPipe, sizeof(syslogPipe));
+     memcpy(¶m->csvlogPipe, &csvlogPipe, sizeof(csvlogPipe));

      strlcpy(param->my_exec_path, my_exec_path, MAXPGPATH);

***************
*** 4158,4163 ****
--- 4170,4176 ----
  #endif

      memcpy(&syslogPipe, ¶m->syslogPipe, sizeof(syslogPipe));
+     memcpy(&csvlogPipe, ¶m->csvlogPipe, sizeof(csvlogPipe));

      strlcpy(my_exec_path, param->my_exec_path, MAXPGPATH);

Index: src/backend/postmaster/syslogger.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/syslogger.c,v
retrieving revision 1.31
diff -c -r1.31 syslogger.c
*** src/backend/postmaster/syslogger.c    4 Jun 2007 22:21:42 -0000    1.31
--- src/backend/postmaster/syslogger.c    6 Jun 2007 19:48:23 -0000
***************
*** 77,99 ****
  static pg_time_t next_rotation_time;

  static bool redirection_done = false;

  static bool pipe_eof_seen = false;

  static FILE *syslogFile = NULL;

  static char *last_file_name = NULL;

  /* 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 sysfileSection;
  #endif

  /*
--- 77,106 ----
  static pg_time_t next_rotation_time;

  static bool redirection_done = false;
+ static bool safe_to_rotate_stderr = true, safe_to_rotate_csv = true;

  static bool pipe_eof_seen = false;

  static FILE *syslogFile = NULL;
+ static FILE *csvlogFile = NULL;

  static char *last_file_name = NULL;

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

  #ifdef WIN32
! static HANDLE syslog_threadHandle = 0;
  static CRITICAL_SECTION sysfileSection;
+
+ static HANDLE csvlog_threadHandle = 0;
+ static CRITICAL_SECTION csvfileSection;
  #endif

  /*
***************
*** 108,123 ****
  static pid_t syslogger_forkexec(void);
  static void syslogger_parseArgs(int argc, char *argv[]);
  #endif

  #ifdef WIN32
  static unsigned int __stdcall pipeThread(void *arg);
  #endif
  static void logfile_rotate(bool time_based_rotation);
! static char *logfile_getname(pg_time_t timestamp);
  static void set_next_rotation_time(void);
  static void sigHupHandler(SIGNAL_ARGS);
  static void sigUsr1Handler(SIGNAL_ARGS);
!

  /*
   * Main entry point for syslogger process
--- 115,133 ----
  static pid_t syslogger_forkexec(void);
  static void syslogger_parseArgs(int argc, char *argv[]);
  #endif
+ static void read_log_pipe(int log_type);

  #ifdef WIN32
  static unsigned int __stdcall pipeThread(void *arg);
  #endif
  static void logfile_rotate(bool time_based_rotation);
! static void logfile_rotate_worker(bool time_based_rotation, int log_type,
!                         char* filename, FILE **dest_file);
! static char *logfile_getname(pg_time_t timestamp, int log_type);
  static void set_next_rotation_time(void);
  static void sigHupHandler(SIGNAL_ARGS);
  static void sigUsr1Handler(SIGNAL_ARGS);
! static int crunch_nuls(const char *buffer, int count);

  /*
   * Main entry point for syslogger process
***************
*** 149,155 ****
       * 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(NULL_DEV, O_WRONLY, 0);

--- 159,165 ----
       * assumes that all interesting messages generated in the syslogger will
       * come through elog.c and will be sent to write_syslogger_file.
       */
!     if ((Redirect_stderr) && (redirection_done) )
      {
          int            fd = open(NULL_DEV, O_WRONLY, 0);

***************
*** 175,184 ****
--- 185,202 ----
      if (syslogPipe[1] >= 0)
          close(syslogPipe[1]);
      syslogPipe[1] = -1;
+
+     if (csvlogPipe[1] >= 0)
+         close(csvlogPipe[1]);
+     csvlogPipe[1] = -1;
  #else
      if (syslogPipe[1])
          CloseHandle(syslogPipe[1]);
      syslogPipe[1] = 0;
+
+     if (csvlogPipe[1])
+         CloseHandle(csvlogPipe[1]);
+     csvlogPipe[1] = 0;
  #endif

      /*
***************
*** 221,233 ****
      PG_SETMASK(&UnBlockSig);

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

      {
          unsigned int tid;

!         threadHandle = (HANDLE) _beginthreadex(0, 0, pipeThread, 0, 0, &tid);
      }
  #endif   /* WIN32 */

--- 239,264 ----
      PG_SETMASK(&UnBlockSig);

  #ifdef WIN32
!     /* Fire up separate data transfer thread for syslog*/
!     if (Redirect_stderr)
!     {
!         unsigned int tid;
!         int logtype = STDERR_LOGFILE;

+         InitializeCriticalSection(&sysfileSection);
+         syslog_threadHandle = (HANDLE) _beginthreadex(0, 0, pipeThread,
+                                 &logtype, 0, &tid);
+     }
+
+     /* Fire up separate data transfer thread for csvlog*/
+     if (Log_destination & LOG_DESTINATION_CSVLOG)
      {
          unsigned int tid;
+         int logtype = CSV_LOGFILE;

!         InitializeCriticalSection(&csvfileSection);
!         csvlog_threadHandle = (HANDLE) _beginthreadex(0, 0, pipeThread,
!                                 &logtype, 0, &tid);
      }
  #endif   /* WIN32 */

***************
*** 243,256 ****
      {
          bool        time_based_rotation = false;

- #ifndef WIN32
-         char        logbuffer[1024];
-         int            bytesRead;
-         int            rc;
-         fd_set        rfds;
-         struct timeval timeout;
- #endif
-
          if (got_SIGHUP)
          {
              got_SIGHUP = false;
--- 274,279 ----
***************
*** 297,365 ****
          if (!rotation_requested && Log_RotationSize > 0)
          {
              /* Do a rotation if file is too big */
!             if (ftell(syslogFile) >= Log_RotationSize * 1024L)
                  rotation_requested = true;
-         }
-
-         if (rotation_requested)
-             logfile_rotate(time_based_rotation);

! #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 = piperead(syslogPipe[0],
-                                  logbuffer, sizeof(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)
!             {
!                 write_syslogger_file(logbuffer, bytesRead);
!                 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;
!             }
!         }
! #else                            /* WIN32 */

!         /*
!          * 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.
!          */
!         pg_usleep(1000000L);
! #endif   /* WIN32 */

          if (pipe_eof_seen)
          {
--- 320,346 ----
          if (!rotation_requested && Log_RotationSize > 0)
          {
              /* Do a rotation if file is too big */
!             if ( (syslogFile) && (ftell(syslogFile) >= Log_RotationSize * 1024L) )
                  rotation_requested = true;

!             /* As a first version, we will rotate both the log
!              * files if either of them is big. The difference
!              * between these two files are not going to be that
!              * great anyway. */
!             if ( (csvlogFile) && (ftell(csvlogFile) >= Log_RotationSize * 1024L) )
!                 rotation_requested = true;
          }

!         if (rotation_requested && safe_to_rotate_stderr && safe_to_rotate_csv)
!             logfile_rotate(time_based_rotation);

!         /* Read the syslog pipe if redirect_stderr is on. */
!         if (Redirect_stderr)
!             read_log_pipe(STDERR_LOGFILE);
!
!         /* Read the csvlog pipe if csvlog is on. */
!         if (Log_destination & LOG_DESTINATION_CSVLOG)
!             read_log_pipe(CSV_LOGFILE);

          if (pipe_eof_seen)
          {
***************
*** 384,393 ****
  int
  SysLogger_Start(void)
  {
      pid_t        sysloggerPid;
-     char       *filename;

!     if (!Redirect_stderr)
          return 0;

      /*
--- 365,376 ----
  int
  SysLogger_Start(void)
  {
+     char    *csv_filename;
+     char    *stderr_filename;
+
      pid_t        sysloggerPid;

!     if ( (!Redirect_stderr) && (!(Log_destination & LOG_DESTINATION_CSVLOG)) )
          return 0;

      /*
***************
*** 402,430 ****
       * pipe open, so we can pass it down to the reincarnated syslogger. This
       * is a bit klugy but we have little choice.
       */
! #ifndef WIN32
!     if (syslogPipe[0] < 0)
      {
!         if (pgpipe(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
--- 385,446 ----
       * pipe open, so we can pass it down to the reincarnated syslogger. This
       * is a bit klugy but we have little choice.
       */
!
!     /* Create the syslog pipe only if we need to redirect stderr */
!     if (Redirect_stderr)
      {
! #ifndef WIN32
!         if (syslogPipe[0] < 0)
!         {
!             if (pgpipe(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, LOG_BUFFER_SIZE))
!                 ereport(FATAL,
!                         (errcode_for_file_access(),
!                          (errmsg("could not create pipe for syslog: %m"))));
!         }
! #endif
      }
+
+     /* Create the csv log pipe if we need csv type log output */
+     if (Log_destination & LOG_DESTINATION_CSVLOG)
+     {
+ #ifndef WIN32
+         if (csvlogPipe[0] < 0)
+         {
+             if (pgpipe(csvlogPipe) < 0)
+                 ereport(FATAL,
+                         (errcode_for_socket_access(),
+                         (errmsg("could not create pipe for csvlog: %m"))));
+         }
+ #else
+         if (!csvlogPipe[0])
+         {
+             SECURITY_ATTRIBUTES sa;
+
+             memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
+             sa.nLength = sizeof(SECURITY_ATTRIBUTES);
+             sa.bInheritHandle = TRUE;
+
+             if (!CreatePipe(&csvlogPipe[0], &csvlogPipe[1], &sa, LOG_BUFFER_SIZE))
+                 ereport(FATAL,
+                         (errcode_for_file_access(),
+                         (errmsg("could not create pipe for csvlog: %m"))));
+         }
  #endif
+     }

      /*
       * Create log directory if not present; ignore errors
***************
*** 435,453 ****
       * The initial logfile is created right in the postmaster, to verify that
       * the Log_directory is writable.
       */
!     filename = logfile_getname(time(NULL));

!     syslogFile = fopen(filename, "a");

!     if (!syslogFile)
!         ereport(FATAL,
                  (errcode_for_file_access(),
                   (errmsg("could not create log file \"%s\": %m",
!                          filename))));

-     setvbuf(syslogFile, NULL, LBF_MODE, 0);

-     pfree(filename);

  #ifdef EXEC_BACKEND
      switch ((sysloggerPid = syslogger_forkexec()))
--- 451,487 ----
       * The initial logfile is created right in the postmaster, to verify that
       * the Log_directory is writable.
       */
!     if (Redirect_stderr)
!     {
!         stderr_filename = logfile_getname(time(NULL), STDERR_LOGFILE);

!         syslogFile = fopen(stderr_filename, "a");
!         if (!syslogFile)
!             ereport(FATAL,
!                 (errcode_for_file_access(),
!                  (errmsg("could not create log file \"%s\": %m",
!                              stderr_filename))));

!         setvbuf(syslogFile, NULL, LBF_MODE, 0);
!         pfree(stderr_filename);
!     }
!
!     if (Log_destination & LOG_DESTINATION_CSVLOG)
!     {
!         csv_filename = logfile_getname(time(NULL), CSV_LOGFILE);
!
!         csvlogFile = fopen(csv_filename, "a");
!         if (!csvlogFile)
!             ereport(FATAL,
                  (errcode_for_file_access(),
                   (errmsg("could not create log file \"%s\": %m",
!                             csv_filename))));
!
!         setvbuf(csvlogFile, NULL, LBF_MODE, 0);
!         pfree(csv_filename);
!     }



  #ifdef EXEC_BACKEND
      switch ((sysloggerPid = syslogger_forkexec()))
***************
*** 481,487 ****
              /* success, in postmaster */

              /* now we redirect stderr, if not done already */
!             if (!redirection_done)
              {
  #ifndef WIN32
                  fflush(stdout);
--- 515,521 ----
              /* success, in postmaster */

              /* now we redirect stderr, if not done already */
!             if (Redirect_stderr && !redirection_done)
              {
  #ifndef WIN32
                  fflush(stdout);
***************
*** 515,523 ****
                  redirection_done = true;
              }

!             /* postmaster will never write the file; close it */
!             fclose(syslogFile);
              syslogFile = NULL;
              return (int) sysloggerPid;
      }

--- 549,563 ----
                  redirection_done = true;
              }

!             /* postmaster will never write the files; close it */
!             if (syslogFile)
!                 fclose(syslogFile);
              syslogFile = NULL;
+
+             if (csvlogFile)
+                 fclose(csvlogFile);
+             csvlogFile = NULL;
+
              return (int) sysloggerPid;
      }

***************
*** 536,546 ****
  static pid_t
  syslogger_forkexec(void)
  {
!     char       *av[10];
!     int            ac = 0,
!                 bufc = 0,
!                 i;
!     char        numbuf[2][32];

      av[ac++] = "postgres";
      av[ac++] = "--forklog";
--- 576,586 ----
  static pid_t
  syslogger_forkexec(void)
  {
!     char    *av[11];
!     int    ac = 0,
!         bufc = 0,
!         i;
!     char    numbuf[3][32];

      av[ac++] = "postgres";
      av[ac++] = "--forklog";
***************
*** 553,558 ****
--- 593,603 ----
      else
          strcpy(numbuf[bufc++], "-1");
      snprintf(numbuf[bufc++], 32, "%d", (int) redirection_done);
+
+     if (csvlogFile != NULL)
+         snprintf(numbuf[bufc++], 32, "%d", fileno(csvlogFile));
+     else
+         strcpy(numbuf[bufc++], "-1");
  #else                            /* WIN32 */
      if (syslogFile != NULL)
          snprintf(numbuf[bufc++], 32, "%ld",
***************
*** 560,565 ****
--- 605,616 ----
      else
          strcpy(numbuf[bufc++], "0");
      snprintf(numbuf[bufc++], 32, "%d", (int) redirection_done);
+
+     if (csvlogFile != NULL)
+         snprintf(numbuf[bufc++], 32, "%ld",
+                  _get_osfhandle(_fileno(csvlogFile)));
+     else
+         strcpy(numbuf[bufc++], "0");
  #endif   /* WIN32 */

      /* Add to the arg list */
***************
*** 583,589 ****
  {
      int            fd;

!     Assert(argc == 5);
      argv += 3;

  #ifndef WIN32
--- 634,640 ----
  {
      int            fd;

!     Assert(argc == 6);
      argv += 3;

  #ifndef WIN32
***************
*** 594,599 ****
--- 645,657 ----
          setvbuf(syslogFile, NULL, LBF_MODE, 0);
      }
      redirection_done = (bool) atoi(*argv++);
+
+     fd = atoi(*argv++);
+     if (fd != -1)
+     {
+         csvlogFile = fdopen(fd, "a");
+         setvbuf(csvlogFile, NULL, LBF_MODE, 0);
+     }
  #else                            /* WIN32 */
      fd = atoi(*argv++);
      if (fd != 0)
***************
*** 606,611 ****
--- 664,680 ----
          }
      }
      redirection_done = (bool) atoi(*argv++);
+
+     fd = atoi(*argv++);
+     if (fd != 0)
+     {
+         fd = _open_osfhandle(fd, _O_APPEND);
+         if (fd > 0)
+         {
+             csvlogFile = fdopen(fd, "a");
+             setvbuf(csvlogFile, NULL, LBF_MODE, 0);
+         }
+     }
  #endif   /* WIN32 */
  }
  #endif   /* EXEC_BACKEND */
***************
*** 616,621 ****
--- 685,715 ----
   * --------------------------------
   */

+ /*
+  * Utility routine to remove the nuls from a string and return the length of
+  * the adjusted string.
+  */
+
+ static int
+ crunch_nuls(const char *buffer, int count)
+ {
+     char *from = buffer;
+     char *to = buffer;
+     int i, newcount = 0;
+
+     for (i = 0; i < count; i++)
+     {
+         char c = *from++;
+         if (c != '\0')
+         {
+             *to++ = c;
+             newcount++;
+         }
+     }
+
+     return newcount;
+ }
+
  /*
   * Write text to the currently open logfile
   *
***************
*** 624,639 ****
   * even though its stderr does not point at the syslog pipe.
   */
  void
! write_syslogger_file(const char *buffer, int count)
  {
!     int            rc;

  #ifndef WIN32
!     rc = fwrite(buffer, 1, count, syslogFile);
  #else
!     EnterCriticalSection(&sysfileSection);
!     rc = fwrite(buffer, 1, count, syslogFile);
!     LeaveCriticalSection(&sysfileSection);
  #endif

      /* can't use ereport here because of possible recursion */
--- 718,762 ----
   * even though its stderr does not point at the syslog pipe.
   */
  void
! write_syslogger_file(const char *buffer, int count, int log_type)
  {
!     int    rc;
!     FILE    **fh = NULL;
!     bool      safe_to_rotate;
!
!     safe_to_rotate = buffer[count-1] == '\0';
!     count = crunch_nuls(buffer, count);
!
!     /* Select the file to write to based on the log_type. */
!     switch (log_type)
!     {
!         case STDERR_LOGFILE:
!             fh = (FILE **) &syslogFile;
!             safe_to_rotate_stderr = safe_to_rotate;
!             break;
!         case CSV_LOGFILE:
!             fh = (FILE **) &csvlogFile;
!             safe_to_rotate_csv = safe_to_rotate;
!             break;
!         default:
!             return;
!     }

  #ifndef WIN32
!     rc = fwrite(buffer, 1, count, *fh);
  #else
!     if (log_type == STDERR_LOGFILE)
!     {
!         EnterCriticalSection(&sysfileSection);
!         rc = fwrite(buffer, 1, count, *fh);
!         LeaveCriticalSection(&sysfileSection);
!     }
!     else if (log_type == CSV_LOGFILE)
!     {
!         EnterCriticalSection(&csvfileSection);
!         rc = fwrite(buffer, 1, count, *fh);
!         LeaveCriticalSection(&csvfileSection);
!     }
  #endif

      /* can't use ereport here because of possible recursion */
***************
*** 656,678 ****
      DWORD        bytesRead;
      char        logbuffer[1024];

!     for (;;)
!     {
!         if (!ReadFile(syslogPipe[0], logbuffer, sizeof(logbuffer),
!                       &bytesRead, 0))
!         {
!             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)
!             write_syslogger_file(logbuffer, bytesRead);
      }

      /* We exit the above loop only upon detecting pipe EOF */
--- 779,833 ----
      DWORD        bytesRead;
      char        logbuffer[1024];

!     int logtype = 0;

!     logtype = *(int *)arg;
!
!     switch (logtype)
!     {
!         case STDERR_LOGFILE:
!             for(;;)
!             {
!                 if (!ReadFile(syslogPipe[0], logbuffer, sizeof(logbuffer),
!                                       &bytesRead, 0))
!                 {
!                     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)
!                     write_syslogger_file(logbuffer, bytesRead,
!                                         STDERR_LOGFILE);
!             }
!             break;
!         case CSV_LOGFILE:
!             for(;;)
!             {
!                 if (!ReadFile(csvlogPipe[0], logbuffer, sizeof(logbuffer),
!                                       &bytesRead, 0))
!                 {
!                     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)
!                     write_syslogger_file(logbuffer, bytesRead, CSV_LOGFILE);
!             }
!             break;
!         default:
!             break;
      }

      /* We exit the above loop only upon detecting pipe EOF */
***************
*** 683,707 ****
  #endif   /* WIN32 */

  /*
!  * perform logfile rotation
   */
  static void
  logfile_rotate(bool time_based_rotation)
  {
!     char       *filename;
!     FILE       *fh;

      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)
!         filename = logfile_getname(next_rotation_time);
!     else
!         filename = logfile_getname(time(NULL));

      /*
       * Decide whether to overwrite or append.  We can overwrite if (a)
--- 838,968 ----
  #endif   /* WIN32 */

  /*
!  * Reads the requested pipe.
!  *
!  * This method is common for both syslog and csvlog pipes.
!  * Based on the log_type this method will know which pipe to read and passes
!  * the data to the appropriate file type.
!  */
! static void
! read_log_pipe(int log_type)
! {
!
! #ifndef WIN32
!     char        logbuffer[1024];
!     int        bytesRead = 0;
!     int        rc;
!     fd_set        rfds;
!     bool        dataInPipe = false;
!     struct timeval timeout;
!
!     /*
!      * Set timeout for a second
!      */
!     timeout.tv_sec = 1;
!     timeout.tv_usec = 0;
!
!     switch (log_type)
!     {
!         case STDERR_LOGFILE:
!             FD_ZERO(&rfds);
!             FD_SET(syslogPipe[0], &rfds);
!             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 = piperead(syslogPipe[0], logbuffer, sizeof(logbuffer));
!                 dataInPipe = true;
!             }
!             break;
!         case CSV_LOGFILE:
!             FD_ZERO(&rfds);
!             FD_SET(csvlogPipe[0], &rfds);
!             rc = select(csvlogPipe[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(csvlogPipe[0], &rfds))
!             {
!                 bytesRead = piperead(csvlogPipe[0], logbuffer, sizeof(logbuffer));
!                 dataInPipe = true;
!             }
!             break;
!         default:
!             return;
!     }
!
!     if (dataInPipe)
!     {
!         if (bytesRead < 0)
!         {
!             if (errno != EINTR)
!                 ereport(LOG,
!                     (errcode_for_socket_access(),
!                     errmsg("could not read from logger pipe: %m")));
!         }
!         else if (bytesRead > 0)
!         {
!             write_syslogger_file(logbuffer, bytesRead, log_type);
!         }
!         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;
!         }
!     }
! #else                        /* WIN32 */
!         /*
!         * 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.
!         */
!         pg_usleep(1000000L);
! #endif   /* WIN32 */
! }
!
! /*
!  * Log file rotation controller. Decides the filename and which file needs
!  * to be rotated. The worker method below this does the actual rotation.
   */
  static void
  logfile_rotate(bool time_based_rotation)
  {
!     char    *filename;
!     char    *csv_filename;
!
!     pg_time_t timestamp;
!     bool overwrite_logfile;

      rotation_requested = false;

+     timestamp = time(NULL);
+     overwrite_logfile = 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)
!         timestamp = next_rotation_time;
!
!     filename = logfile_getname(timestamp, STDERR_LOGFILE);

      /*
       * Decide whether to overwrite or append.  We can overwrite if (a)
***************
*** 717,722 ****
--- 978,1013 ----
       */
      if (Log_truncate_on_rotation && time_based_rotation &&
          last_file_name != NULL && strcmp(filename, last_file_name) != 0)
+         overwrite_logfile = true;
+
+     if (Redirect_stderr)
+         logfile_rotate_worker(overwrite_logfile, STDERR_LOGFILE, filename,
+                         (FILE **) &syslogFile);
+
+     if (Log_destination & LOG_DESTINATION_CSVLOG)
+     {
+         csv_filename = logfile_getname(timestamp, CSV_LOGFILE);
+         logfile_rotate_worker(overwrite_logfile, CSV_LOGFILE, csv_filename,
+                         (FILE **) &csvlogFile);
+     }
+
+     set_next_rotation_time();
+
+     /* instead of pfree'ing filename, remember it for next time */
+     if (last_file_name != NULL)
+         pfree(last_file_name);
+     last_file_name = filename;
+ }
+
+ /*
+  * logfile rotation worker - Does the actual file rotation
+  */
+ static void
+ logfile_rotate_worker(bool overwrite_logfile, int log_type, char* filename, FILE **dest_file)
+ {
+     FILE       *fh;
+
+     if (overwrite_logfile)
          fh = fopen(filename, "w");
      else
          fh = fopen(filename, "a");
***************
*** 751,780 ****

      /* On Windows, need to interlock against data-transfer thread */
  #ifdef WIN32
!     EnterCriticalSection(&sysfileSection);
  #endif
!     fclose(syslogFile);
!     syslogFile = fh;
  #ifdef WIN32
!     LeaveCriticalSection(&sysfileSection);
  #endif
-
-     set_next_rotation_time();
-
-     /* instead of pfree'ing filename, remember it for next time */
-     if (last_file_name != NULL)
-         pfree(last_file_name);
-     last_file_name = filename;
  }


  /*
!  * construct logfile name using timestamp information
   *
   * Result is palloc'd.
   */
  static char *
! logfile_getname(pg_time_t timestamp)
  {
      char       *filename;
      int            len;
--- 1042,1071 ----

      /* On Windows, need to interlock against data-transfer thread */
  #ifdef WIN32
!     if (log_type == STDERR_LOGFILE)
!         EnterCriticalSection(&sysfileSection);
!     else
!         EnterCriticalSection(&csvfileSection);
  #endif
!     fclose(*dest_file);
!     *dest_file = fh;
  #ifdef WIN32
!     if (log_type == STDERR_LOGFILE)
!         LeaveCriticalSection(&sysfileSection);
!     else
!         LeaveCriticalSection(&csvfileSection);
  #endif
  }


  /*
!  * construct logfile name using timestamp information. Adds a '.csv' as
!  * extension to csvlog files if enabled.
   *
   * Result is palloc'd.
   */
  static char *
! logfile_getname(pg_time_t timestamp, int log_type)
  {
      char       *filename;
      int            len;
***************
*** 799,804 ****
--- 1090,1102 ----
                   Log_filename, (unsigned long) timestamp);
      }

+     if (log_type == CSV_LOGFILE)
+     {
+         len = strlen(filename);
+         /* Append .csv to the new filename */
+         snprintf(filename + len, MAXPGPATH - len, ".csv");
+     }
+
      return filename;
  }

Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/error/elog.c,v
retrieving revision 1.185
diff -c -r1.185 elog.c
*** src/backend/utils/error/elog.c    4 May 2007 02:01:02 -0000    1.185
--- src/backend/utils/error/elog.c    6 Jun 2007 19:48:24 -0000
***************
*** 78,83 ****
--- 78,85 ----

  extern pid_t SysLoggerPID;

+ char timestamp[128];
+
  /* GUC parameters */
  PGErrorVerbosity Log_error_verbosity = PGERROR_VERBOSE;
  char       *Log_line_prefix = NULL;        /* format for extra log line info */
***************
*** 125,130 ****
--- 127,136 ----
  static void append_with_tabs(StringInfo buf, const char *str);
  static bool is_log_level_output(int elevel, int log_min_level);

+ static void write_csvlog(ErrorData *edata);
+ static void get_error_message(StringInfo buf, ErrorData *edata);
+ static void get_timestamp(StringInfo buf);
+ static size_t escape_string_literal(char *to, const char *from);

  /*
   * errstart --- begin an error-reporting cycle
***************
*** 1493,1533 ****
                  appendStringInfo(buf, "%ld", log_line_number);
                  break;
              case 'm':
!                 {
!                     /*
!                      * Note: for %m, %t, and %s we deliberately use the C
!                      * library's strftime/localtime, and not the equivalent
!                      * functions from src/timezone.  This ensures that all
!                      * backends will report log entries in the same timezone,
!                      * namely whatever C-library setting they inherit from the
!                      * postmaster.    If we used src/timezone then local
!                      * settings of the TimeZone GUC variable would confuse the
!                      * log.
!                      */
!                     time_t        stamp_time;
!                     char        strfbuf[128],
!                                 msbuf[8];
!                     struct timeval tv;
!
!                     gettimeofday(&tv, NULL);
!                     stamp_time = tv.tv_sec;
!
!                     strftime(strfbuf, sizeof(strfbuf),
!                     /* leave room for milliseconds... */
!                     /* Win32 timezone names are too long so don't print them */
! #ifndef WIN32
!                              "%Y-%m-%d %H:%M:%S     %Z",
! #else
!                              "%Y-%m-%d %H:%M:%S     ",
! #endif
!                              localtime(&stamp_time));
!
!                     /* 'paste' milliseconds into place... */
!                     sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
!                     strncpy(strfbuf + 19, msbuf, 4);
!
!                     appendStringInfoString(buf, strfbuf);
!                 }
                  break;
              case 't':
                  {
--- 1499,1505 ----
                  appendStringInfo(buf, "%ld", log_line_number);
                  break;
              case 'm':
!                 get_timestamp(buf);
                  break;
              case 't':
                  {
***************
*** 1639,1644 ****
--- 1611,1617 ----
  {
      StringInfoData buf;

+     memset(timestamp, '\0', sizeof(timestamp));
      initStringInfo(&buf);

      log_line_prefix(&buf);
***************
*** 1647,1663 ****
      if (Log_error_verbosity >= PGERROR_VERBOSE)
          appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode));

!     if (edata->message)
!         append_with_tabs(&buf, edata->message);
!     else
!         append_with_tabs(&buf, _("missing error text"));
!
!     if (edata->cursorpos > 0)
!         appendStringInfo(&buf, _(" at character %d"),
!                          edata->cursorpos);
!     else if (edata->internalpos > 0)
!         appendStringInfo(&buf, _(" at character %d"),
!                          edata->internalpos);

      appendStringInfoChar(&buf, '\n');

--- 1620,1627 ----
      if (Log_error_verbosity >= PGERROR_VERBOSE)
          appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode));

!     /* Get the error message and cursor position if any */
!     get_error_message(&buf, edata);

      appendStringInfoChar(&buf, '\n');

***************
*** 1772,1778 ****
  #endif   /* WIN32 */

      /* Write to stderr, if enabled */
!     if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug)
      {
  #ifdef WIN32

--- 1736,1743 ----
  #endif   /* WIN32 */

      /* Write to stderr, if enabled */
!     if ((Log_destination & LOG_DESTINATION_STDERR) ||
!         whereToSendOutput == DestDebug)
      {
  #ifdef WIN32

***************
*** 1784,1799 ****
           * that's really a pipe to the syslogger process. Unless we're in the
           * postmaster, and the syslogger process isn't started yet.
           */
!         if ((!Redirect_stderr || am_syslogger || (!IsUnderPostmaster && SysLoggerPID==0)) && pgwin32_is_service())
              write_eventlog(edata->elevel, buf.data);
          else
  #endif
!             fprintf(stderr, "%s", buf.data);
      }

!     /* If in the syslogger process, try to write messages direct to file */
      if (am_syslogger)
!         write_syslogger_file(buf.data, buf.len);

      pfree(buf.data);
  }
--- 1749,1782 ----
           * that's really a pipe to the syslogger process. Unless we're in the
           * postmaster, and the syslogger process isn't started yet.
           */
!         if ((!Redirect_stderr || am_syslogger ||
!              (!IsUnderPostmaster && SysLoggerPID==0)) && pgwin32_is_service())
              write_eventlog(edata->elevel, buf.data);
          else
  #endif
!
!         /*
!          * If writing into the pipe, add the trailing nul so the
!          * syslogger will know when it gets to a genuine end of line.
!          */
!          write(fileno(stderr), buf.data,
!                Redirect_stderr? buf.len+1 : buf.len);
      }

!
!     /* Output log in csv format, if enabled */
!     if(Log_destination & LOG_DESTINATION_CSVLOG)
!         write_csvlog(edata);
!
!     /*
!      * If in the syslogger process, write messages direct to file,
!      * regardless of what Log_destination is set to, to try to make sure
!      * something gets logged.
!      */
!
      if (am_syslogger)
!         write_syslogger_file(buf.data, buf.len+1, STDERR_LOGFILE);
!

      pfree(buf.data);
  }
***************
*** 2170,2172 ****
--- 2153,2469 ----

      return false;
  }
+
+
+ /*
+  * Constructs the error message, depending on the Errordata it gets,
+  * in CSV (comma seperated values) format. The COPY command
+  * can then be used to load the messages into a table.
+  */
+ static void
+ write_csvlog(ErrorData *edata)
+ {
+     char *csv_log_stmt = NULL;
+     StringInfoData msgbuf;
+     StringInfoData buf;
+
+     /* static counter for line numbers */
+     static long log_line_number = 0;
+
+     /* has counter been reset in current process? */
+     static int  log_my_pid = 0;
+
+     /*
+      * This is one of the few places where we'd rather not inherit a static
+      * variable's value from the postmaster.  But since we will, reset it when
+      * MyProcPid changes.
+      */
+     if (log_my_pid != MyProcPid)
+     {
+         log_line_number = 0;
+         log_my_pid = MyProcPid;
+     }
+     log_line_number++;
+
+     initStringInfo(&msgbuf);
+     initStringInfo(&buf);
+
+     /*
+      * The format of the log output in CSV format:
+      * timestamp with milliseconds, username, databasename, session id,
+      * host and port number, process id, process line number, command tag,
+      * session start time, transaction id, error severity, sql state code,
+      * statement or error message.
+      */
+
+     /* timestamp_with_milliseconds */
+     /*
+      * Check if the timestamp is already calculated for the syslog message,
+      * if it is, then no need to calculate it again, will use the same,
+      * else get the current timestamp. This is done to put same timestamp
+      * in both syslog and csvlog messages.
+      */
+     if (timestamp[0] == '\0')
+         get_timestamp(&buf);
+     else
+         appendStringInfoString(&buf, timestamp);
+
+     appendStringInfoString(&buf, ",");
+
+     /* username */
+     if (MyProcPort)
+     {
+         const char *username = MyProcPort->user_name;
+         if (username == NULL || *username == '\0')
+             username = _("[unknown]");
+
+         csv_log_stmt = palloc(strlen(username) * 2 + 1);
+         escape_string_literal(csv_log_stmt, username);
+         appendStringInfo(&buf, "\"%s\",", csv_log_stmt);
+         pfree(csv_log_stmt);
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* databasename */
+     if (MyProcPort)
+     {
+         const char *dbname = MyProcPort->database_name;
+
+         if (dbname == NULL || *dbname == '\0')
+             dbname = _("[unknown]");
+
+         csv_log_stmt = palloc(strlen(dbname) * 2 + 1);
+         escape_string_literal(csv_log_stmt, dbname);
+         appendStringInfo(&buf, "\"%s\",", csv_log_stmt);
+         pfree(csv_log_stmt);
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* session id */
+     if (MyProcPort)
+     {
+         appendStringInfo(&buf, "%lx.%x,",
+                  (long) (MyProcPort->session_start), MyProcPid);
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* Remote host and port */
+     if (MyProcPort)
+     {
+         if (MyProcPort->remote_host)
+         {
+             appendStringInfo(&buf, "%s", MyProcPort->remote_host);
+             if (MyProcPort->remote_port &&
+                 MyProcPort->remote_port[0] != '\0')
+                 appendStringInfo(&buf, ":%s,",
+                          MyProcPort->remote_port);
+             else
+                 appendStringInfoString(&buf, ",");
+         }
+         else
+             appendStringInfoString(&buf, ",");
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* Process id and line number */
+     if (MyProcPid != 0)
+         appendStringInfo(&buf, "%d,%ld,", MyProcPid, log_line_number);
+     else
+         appendStringInfo(&buf, ",%ld,", log_line_number);
+
+     /* Command tag */
+     if (MyProcPort)
+     {
+         const char *psdisp;
+         int            displen;
+
+         psdisp = get_ps_display(&displen);
+         appendStringInfo(&buf, "%.*s,", displen, psdisp);
+     }
+     else
+     appendStringInfoString(&buf, ",");
+
+     /* session start timestamp */
+     if (MyProcPort)
+     {
+         char        strfbuf[128];
+ #ifdef WIN32
+         DWORD       writtenbytes;
+ #endif
+
+         strftime(strfbuf, sizeof(strfbuf),
+         /* Win32 timezone names are too long so don't print them */
+ #ifndef WIN32
+              "%Y-%m-%d %H:%M:%S %Z",
+ #else
+              "%Y-%m-%d %H:%M:%S",
+ #endif
+         localtime(&MyProcPort->session_start));
+         appendStringInfoString(&buf, strfbuf);
+         appendStringInfoString(&buf, ",");
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* Transaction id */
+     if (MyProcPort)
+     {
+         if (IsTransactionState())
+             appendStringInfo(&buf, "%u,", GetTopTransactionId());
+         else
+             appendStringInfo(&buf, "%u,", InvalidTransactionId);
+     }
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* Error severity */
+     if (error_severity(edata->elevel) != NULL)
+         appendStringInfo(&buf, "%s,", error_severity(edata->elevel));
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* SQL state code */
+     if (Log_error_verbosity >= PGERROR_VERBOSE)
+         appendStringInfo(&buf, "%s,",
+                  unpack_sql_state(edata->sqlerrcode));
+     else
+         appendStringInfoString(&buf, ",");
+
+     /* Error message and cursor position if any */
+     get_error_message(&msgbuf, edata);
+     csv_log_stmt = palloc(strlen(msgbuf.data) * 2 + 1);
+     escape_string_literal(csv_log_stmt, msgbuf.data);
+
+     appendStringInfo(&buf, "\"%s\"", csv_log_stmt);
+     appendStringInfoString(&buf, "\n");
+
+     /*
+      * When we write a CSV line we want a trailing nul sent so that the
+      * syslogger knows it is at the end of a line, rather than at an embedded
+      * linefeed. A StringInfo is already guaranteed to have a trailing nul,
+      * so all we need to do is write out len+1 bytes to get the nul sent.
+      */
+
+
+     /* If in the syslogger process, try to write messages direct to file */
+     if (am_syslogger)
+         write_syslogger_file(buf.data, buf.len+1, CSV_LOGFILE);
+     else
+ #ifdef WIN32
+         WriteFile(csvlogPipe[1], buf.data, buf.len+1, &writtenbytes, NULL);
+ #else
+         write(csvlogPipe[1], buf.data, buf.len+1);
+ #endif
+
+     pfree(csv_log_stmt);
+     pfree(msgbuf.data);
+     pfree(buf.data);
+ }
+
+ /*
+  * Appends the buffer with the error message and the cursor position.
+  */
+ static void
+ get_error_message(StringInfo buf, ErrorData *edata)
+ {
+     StringInfoData msgbuf;
+
+     initStringInfo(&msgbuf);
+
+     if (edata->message)
+         append_with_tabs(&msgbuf, edata->message);
+     else
+         append_with_tabs(&msgbuf, _("missing error text"));
+
+     if (edata->cursorpos > 0)
+         appendStringInfo(&msgbuf, _(" at character %d"),
+                          edata->cursorpos);
+     else if (edata->internalpos > 0)
+         appendStringInfo(&msgbuf, _(" at character %d"),
+                          edata->internalpos);
+     appendStringInfo(buf, "%s", pstrdup(msgbuf.data));
+ }
+
+ /*
+  * Calculates the current timestamp. Appends the calculated timestamp
+  * to the buffer passed in.
+  */
+ static void
+ get_timestamp(StringInfo buf)
+ {
+     /*
+      * Note: for %m, %t, and %s we deliberately use the C
+      * library's strftime/localtime, and not the equivalent
+      * functions from src/timezone.  This ensures that all
+      * backends will report log entries in the same timezone,
+      * namely whatever C-library setting they inherit from the
+      * postmaster.    If we used src/timezone then local
+      * settings of the TimeZone GUC variable would confuse the
+      * log.
+      */
+     time_t        stamp_time;
+     char        msbuf[8];
+     struct timeval tv;
+
+     gettimeofday(&tv, NULL);
+     stamp_time = tv.tv_sec;
+
+     strftime(timestamp, sizeof(timestamp),
+     /* leave room for milliseconds... */
+     /* Win32 timezone names are too long so don't print them. */
+ #ifndef WIN32
+          "%Y-%m-%d %H:%M:%S     %Z",
+ #else
+          "%Y-%m-%d %H:%M:%S     ",
+ #endif
+     localtime(&stamp_time));
+
+     /* 'paste' milliseconds into place... */
+     sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
+     strncpy(timestamp + 19, msbuf, 4);
+
+     appendStringInfoString(buf, timestamp);
+ }
+
+ /*
+  * Escapes special characters in the string to conform
+  * with the csv type output.
+  * Replaces " with "", since that is the PostgreSQL default for QUOTE/ESCAPE
+  */
+ static size_t
+ escape_string_literal(char *to, const char *from)
+ {
+     const char *source = from;
+     char       *target = to;
+     size_t        remaining = 0;
+     int    client_encoding = 0;
+
+     if (from == NULL)
+         return remaining;
+
+     remaining = strlen(from);
+
+     while (remaining > 0 && *source != '\0')
+     {
+         char        c = *source;
+         int            len;
+         int            i;
+
+         /* Apply quoting if needed */
+         if (c == '"')
+             *target++ = c;
+         /* Copy the character */
+         *target++ = c;
+         source++;
+         remaining--;
+     }
+
+     /* Write the terminating NUL character. */
+     *target = '\0';
+
+     return target - to;
+ }
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v
retrieving revision 1.395
diff -c -r1.395 guc.c
*** src/backend/utils/misc/guc.c    5 Jun 2007 21:50:19 -0000    1.395
--- src/backend/utils/misc/guc.c    6 Jun 2007 19:48:28 -0000
***************
*** 2192,2198 ****
      {
          {"log_destination", PGC_SIGHUP, LOGGING_WHERE,
              gettext_noop("Sets the destination for server log output."),
!             gettext_noop("Valid values are combinations of \"stderr\", \"syslog\", "
                           "and \"eventlog\", depending on the platform."),
              GUC_LIST_INPUT
          },
--- 2192,2198 ----
      {
          {"log_destination", PGC_SIGHUP, LOGGING_WHERE,
              gettext_noop("Sets the destination for server log output."),
!             gettext_noop("Valid values are combinations of \"stderr\", \"syslog\", \"csvlog\","
                           "and \"eventlog\", depending on the platform."),
              GUC_LIST_INPUT
          },
***************
*** 6162,6167 ****
--- 6162,6169 ----

          if (pg_strcasecmp(tok, "stderr") == 0)
              newlogdest |= LOG_DESTINATION_STDERR;
+         else if (pg_strcasecmp(tok, "csvlog") == 0)
+             newlogdest |= LOG_DESTINATION_CSVLOG;
  #ifdef HAVE_SYSLOG
          else if (pg_strcasecmp(tok, "syslog") == 0)
              newlogdest |= LOG_DESTINATION_SYSLOG;
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.216
diff -c -r1.216 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample    3 Jun 2007 17:08:15 -0000    1.216
--- src/backend/utils/misc/postgresql.conf.sample    6 Jun 2007 19:48:29 -0000
***************
*** 227,233 ****
  # - Where to Log -

  #log_destination = 'stderr'        # Valid values are combinations of
!                     # stderr, syslog and eventlog,
                      # depending on platform.

  # This is used when logging to stderr:
--- 227,233 ----
  # - Where to Log -

  #log_destination = 'stderr'        # Valid values are combinations of
!                     # stderr, syslog, csvlog and eventlog,
                      # depending on platform.

  # This is used when logging to stderr:
***************
*** 235,241 ****
                      # files
                      # (change requires restart)

! # These are only used if redirect_stderr is on:
  #log_directory = 'pg_log'        # Directory where log files are written
                      # Can be absolute or relative to PGDATA
  #log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # Log file name pattern.
--- 235,241 ----
                      # files
                      # (change requires restart)

! # These are only used if redirect_stderr is on, or if log_destination is csvlog:
  #log_directory = 'pg_log'        # Directory where log files are written
                      # Can be absolute or relative to PGDATA
  #log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # Log file name pattern.
Index: src/include/postmaster/syslogger.h
===================================================================
RCS file: /cvsroot/pgsql/src/include/postmaster/syslogger.h,v
retrieving revision 1.8
diff -c -r1.8 syslogger.h
*** src/include/postmaster/syslogger.h    5 Jan 2007 22:19:57 -0000    1.8
--- src/include/postmaster/syslogger.h    6 Jun 2007 19:48:29 -0000
***************
*** 12,17 ****
--- 12,23 ----
  #ifndef _SYSLOGGER_H
  #define _SYSLOGGER_H

+ #define LOG_BUFFER_SIZE    32768
+
+ #define STDERR_LOGFILE    1
+ #define CSV_LOGFILE    2
+
+
  /* GUC options */
  extern bool Redirect_stderr;
  extern int    Log_RotationAge;
***************
*** 24,37 ****

  #ifndef WIN32
  extern int    syslogPipe[2];
  #else
  extern HANDLE syslogPipe[2];
  #endif


  extern int    SysLogger_Start(void);

! extern void write_syslogger_file(const char *buffer, int count);

  #ifdef EXEC_BACKEND
  extern void SysLoggerMain(int argc, char *argv[]);
--- 30,45 ----

  #ifndef WIN32
  extern int    syslogPipe[2];
+ extern int    csvlogPipe[2];
  #else
  extern HANDLE syslogPipe[2];
+ extern HANDLE csvlogPipe[2];
  #endif


  extern int    SysLogger_Start(void);

! extern void write_syslogger_file(const char *buffer, int count, int log_type);

  #ifdef EXEC_BACKEND
  extern void SysLoggerMain(int argc, char *argv[]);
Index: src/include/utils/elog.h
===================================================================
RCS file: /cvsroot/pgsql/src/include/utils/elog.h,v
retrieving revision 1.86
diff -c -r1.86 elog.h
*** src/include/utils/elog.h    4 May 2007 02:01:02 -0000    1.86
--- src/include/utils/elog.h    6 Jun 2007 19:48:30 -0000
***************
*** 291,296 ****
--- 291,297 ----
  #define LOG_DESTINATION_STDERR     1
  #define LOG_DESTINATION_SYSLOG     2
  #define LOG_DESTINATION_EVENTLOG 4
+ #define LOG_DESTINATION_CSVLOG    8

  /* Other exported functions */
  extern void DebugFileOpen(void);

Re: WIP csv logs

From
Alvaro Herrera
Date:
Andrew Dunstan wrote:
>
> Attached is my WIP version of the CSV logs patch. It does not include
> docs changes.
>
> It fixes the CSV thinko I just posted about, and also implements the
> "safe to rotate" scheme I suggested yesterday, at quite a modest cost.
> As Tom rightly points out, that does not protect us against interleaving
> log lines from different backends, which is an open problem.

I wonder, if we were to use an LWLock to protect writing to the stderr
pipe, would it be too contentious?

--
Alvaro Herrera       Valdivia, Chile   ICBM: S 39º 49' 18.1", W 73º 13' 56.4"
"El destino baraja y nosotros jugamos" (A. Schopenhauer)

Re: WIP csv logs

From
Andrew Dunstan
Date:

Alvaro Herrera wrote:
> Andrew Dunstan wrote:
>
>> Attached is my WIP version of the CSV logs patch. It does not include
>> docs changes.
>>
>> It fixes the CSV thinko I just posted about, and also implements the
>> "safe to rotate" scheme I suggested yesterday, at quite a modest cost.
>> As Tom rightly points out, that does not protect us against interleaving
>> log lines from different backends, which is an open problem.
>>
>
> I wonder, if we were to use an LWLock to protect writing to the stderr
> pipe, would it be too contentious?
>
>
That was the first thing I wanted to try. I'll code it up and then
people can test to see if we get a significant performance hit.

cheers

andrew


Re: WIP csv logs

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> I wonder, if we were to use an LWLock to protect writing to the stderr
> pipe, would it be too contentious?

Sorry, that's a nonstarter.

1. Not all our processes are connected to shared memory.  Even the ones
that are don't necessarily have PGPROCs.

2. If somebody crashes while holding the lock, the entire system
including the postmaster soon freezes up.

3. Having the postmaster take LWLocks is verboten anyway, mainly because
of problem #2.

            regards, tom lane

Re: WIP csv logs

From
Andrew Dunstan
Date:

Tom Lane wrote:
> Alvaro Herrera <alvherre@commandprompt.com> writes:
>
>> I wonder, if we were to use an LWLock to protect writing to the stderr
>> pipe, would it be too contentious?
>>
>
> Sorry, that's a nonstarter.
>
> 1. Not all our processes are connected to shared memory.  Even the ones
> that are don't necessarily have PGPROCs.
>
> 2. If somebody crashes while holding the lock, the entire system
> including the postmaster soon freezes up.
>
> 3. Having the postmaster take LWLocks is verboten anyway, mainly because
> of problem #2.
>
>
>

Ugh. Well, until this problem is solved I'm not prepared to commit a
patch that purports to provide machine readable logs. The only
non-locking solution I can think of is to have one set of pipes per
backend rather than one set per cluster. That could get pretty ugly,
though, and have all sorts of problems with portability.

I'm starting to wonder if the CSVlog patch needs to be put on hold at
least for 8.4. If we do, I think I should at least commit the piece that
prevents rotation in the middle of a line, and possible even backpatch it.

cheers

andrew