Here's my latest WIP patch for COPYable CSV logs. I think I addresses all (or most :-) ) of the concerns Dave and Tom had. It's a whole lot simpler than before (no extra pipe).


I have not yet tested this on Windows, but given that it now contains almost no Windows-specific code I'm not so worried about it - will test when I get a chance.

Comments welcome.

cheers

andrew


Index: src/backend/postmaster/syslogger.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/syslogger.c,v
retrieving revision 1.36
diff -c -r1.36 syslogger.c
*** src/backend/postmaster/syslogger.c	4 Aug 2007 01:26:53 -0000	1.36
--- src/backend/postmaster/syslogger.c	7 Aug 2007 12:25:29 -0000
***************
*** 87,93 ****
--- 87,95 ----
  static pg_time_t next_rotation_time;
  static bool pipe_eof_seen = false;
  static FILE *syslogFile = NULL;
+ static FILE *csvlogFile = NULL;
  static char *last_file_name = NULL;
+ static char *last_csvfile_name = NULL;
  
  /* 
   * Buffers for saving partial messages from different backends. We don't expect
***************
*** 132,143 ****
  #endif
  static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
  static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
  
  #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);
--- 134,146 ----
  #endif
  static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
  static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
+ static void open_csvlogfile(void);
  
  #ifdef WIN32
  static unsigned int __stdcall pipeThread(void *arg);
  #endif
! static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
! static char *logfile_getname(pg_time_t timestamp, char * suffix);
  static void set_next_rotation_time(void);
  static void sigHupHandler(SIGNAL_ARGS);
  static void sigUsr1Handler(SIGNAL_ARGS);
***************
*** 281,287 ****
  	for (;;)
  	{
  		bool		time_based_rotation = false;
! 
  #ifndef WIN32
  		int			bytesRead;
  		int			rc;
--- 284,290 ----
  	for (;;)
  	{
  		bool		time_based_rotation = false;
! 		int         size_rotation_for = 0;
  #ifndef WIN32
  		int			bytesRead;
  		int			rc;
***************
*** 336,346 ****
  		{
  			/* 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
  
--- 339,358 ----
  		{
  			/* Do a rotation if file is too big */
  			if (ftell(syslogFile) >= Log_RotationSize * 1024L)
+ 			{
+ 				rotation_requested = true;
+ 				size_rotation_for |= LOG_DESTINATION_STDERR;
+ 			}
+ 			if (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L)
+ 			{
  				rotation_requested = true;
+ 				size_rotation_for |= LOG_DESTINATION_CSVLOG;
+ 			}
+ 				
  		}
  
  		if (rotation_requested)
! 			logfile_rotate(time_based_rotation, size_rotation_for);
  
  #ifndef WIN32
  
***************
*** 405,411 ****
  
  		if (pipe_eof_seen)
  		{
! 			ereport(LOG,
  					(errmsg("logger shutting down")));
  
  			/*
--- 417,426 ----
  
  		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("logger shutting down")));
  
  			/*
***************
*** 477,483 ****
  	 * 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");
  
--- 492,498 ----
  	 * The initial logfile is created right in the postmaster, to verify that
  	 * the Log_directory is writable.
  	 */
! 	filename = logfile_getname(time(NULL), NULL);
  
  	syslogFile = fopen(filename, "a");
  
***************
*** 688,693 ****
--- 703,709 ----
  {
  	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) sizeof(PipeProtoHeader))
***************
*** 700,706 ****
  		if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
  			p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
  			p.pid != 0 &&
! 			(p.is_last == 't' || p.is_last == 'f'))
  		{
  			chunklen = PIPE_HEADER_SIZE + p.len;
  
--- 716,723 ----
  		if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
  			p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
  			p.pid != 0 &&
! 			(p.is_last == 't' || p.is_last == 'f' || 
! 			 p.is_last == 'T' || p.is_last == 'F' ))
  		{
  			chunklen = PIPE_HEADER_SIZE + p.len;
  
***************
*** 708,713 ****
--- 725,733 ----
  			if (count < chunklen)
  				break;
  
+ 			if (p.is_last == 'T' || p.is_last == 'F' )
+ 				dest = LOG_DESTINATION_CSVLOG;
+ 
  			if (p.is_last == 'f')
  			{
  				/* 
***************
*** 751,757 ****
  					 * chances and write out a partial message and hope that
  					 * it's not followed by something from another pid.
  					 */
! 					write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len);
  				}
  			}
  			else
--- 771,778 ----
  					 * chances and write out a partial message and hope that
  					 * it's not followed by something from another pid.
  					 */
! 					write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len, 
! 										 dest);
  				}
  			}
  			else
***************
*** 778,791 ****
  					appendBinaryStringInfo(str,
  										   cursor + PIPE_HEADER_SIZE,
  										   p.len);
! 					write_syslogger_file(str->data, str->len);
  					saved_chunks[existing_slot].pid = 0;
  					pfree(str->data);
  				}
  				else
  				{
  					/* The whole message was one chunk, evidently. */
! 					write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len);
  				}
  			}
  
--- 799,813 ----
  					appendBinaryStringInfo(str,
  										   cursor + PIPE_HEADER_SIZE,
  										   p.len);
! 					write_syslogger_file(str->data, str->len, p.is_last);
  					saved_chunks[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);
  				}
  			}
  
***************
*** 811,817 ****
  				if (cursor[chunklen] == '\0')
  					break;
  			}
! 			write_syslogger_file(cursor, chunklen);
  			cursor += chunklen;
  			count -= chunklen;
  		}
--- 833,840 ----
  				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;
  		}
***************
*** 841,847 ****
  		if (saved_chunks[i].pid != 0)
  		{
  			str = &(saved_chunks[i].data);
! 			write_syslogger_file(str->data, str->len);
  			saved_chunks[i].pid = 0;
  			pfree(str->data);
  		}
--- 864,870 ----
  		if (saved_chunks[i].pid != 0)
  		{
  			str = &(saved_chunks[i].data);
! 			write_syslogger_file(str->data, str->len, LOG_DESTINATION_STDERR);
  			saved_chunks[i].pid = 0;
  			pfree(str->data);
  		}
***************
*** 851,857 ****
  	 * remove any protocol headers that may exist in it.
  	 */
  	if (*bytes_in_logbuffer > 0)
! 		write_syslogger_file(logbuffer, *bytes_in_logbuffer);
  	*bytes_in_logbuffer = 0;
  }
  
--- 874,881 ----
  	 * 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;
  }
  
***************
*** 869,883 ****
   * 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
  
--- 893,913 ----
   * 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 (destination == LOG_DESTINATION_CSVLOG && csvlogFile == NULL)
+ 		open_csvlogfile();
+ 
+ 	logfile = destination == LOG_DESTINATION_CSVLOG ? csvlogFile : syslogFile ;
  
  #ifndef WIN32
! 	rc = fwrite(buffer, 1, count, logfile);
  #else
  	EnterCriticalSection(&sysfileSection);
! 	rc = fwrite(buffer, 1, count, logfile);
  	LeaveCriticalSection(&sysfileSection);
  #endif
  
***************
*** 939,950 ****
  #endif   /* WIN32 */
  
  /*
   * perform logfile rotation
   */
  static void
! logfile_rotate(bool time_based_rotation)
  {
  	char	   *filename;
  	FILE	   *fh;
  
  	rotation_requested = false;
--- 969,1013 ----
  #endif   /* WIN32 */
  
  /*
+  * open the csv log file - we do this opportunistically, because 
+  * we don't know if CSV logging will be wanted.
+  */
+ static void
+ open_csvlogfile(void)
+ {
+ 	char *filename;
+ 	FILE *fh;
+ 
+ 	filename = logfile_getname(time(NULL),".csv");
+ 
+ 	fh = fopen(filename, "a");
+ 
+ 	if (!fh)
+ 		ereport(FATAL,
+ 				(errcode_for_file_access(),
+ 				 (errmsg("could not create log file \"%s\": %m",
+ 						 filename))));
+ 
+ 	setvbuf(fh, NULL, LBF_MODE, 0);
+ 
+ #ifdef WIN32
+ 	_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
+ #endif
+ 
+ 	csvlogFile = fh;
+ 
+ 	pfree(filename);
+ 
+ }
+ 
+ /*
   * perform logfile rotation
   */
  static void
! logfile_rotate(bool time_based_rotation, int size_rotation_for)
  {
  	char	   *filename;
+ 	char       *csvfilename;
  	FILE	   *fh;
  
  	rotation_requested = false;
***************
*** 955,963 ****
  	 * 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)
--- 1018,1034 ----
  	 * file name when we don't do the rotation immediately.
  	 */
  	if (time_based_rotation)
! 	{
! 		filename = logfile_getname(next_rotation_time, NULL);
! 		if (csvlogFile != NULL)
! 			csvfilename = logfile_getname(next_rotation_time, ".csv");
! 	}
  	else
! 	{
! 		filename = logfile_getname(time(NULL), NULL);
! 		if (csvlogFile != NULL)
! 			csvfilename = logfile_getname(time(NULL), ".csv");
! 	}
  
  	/*
  	 * Decide whether to overwrite or append.  We can overwrite if (a)
***************
*** 970,1030 ****
  	 * postmaster because it ain't gonna work in the EXEC_BACKEND case.) So we
  	 * will always append in that situation, even though truncating would
  	 * usually be safe.
  	 */
! 	if (Log_truncate_on_rotation && time_based_rotation &&
! 		last_file_name != NULL && strcmp(filename, last_file_name) != 0)
! 		fh = fopen(filename, "w");
! 	else
! 		fh = fopen(filename, "a");
! 
! 	if (!fh)
  	{
! 		int			saveerrno = errno;
! 
! 		ereport(LOG,
! 				(errcode_for_file_access(),
! 				 errmsg("could not open new log file \"%s\": %m",
! 						filename)));
  
! 		/*
! 		 * 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 (saveerrno != ENFILE && saveerrno != EMFILE)
  		{
  			ereport(LOG,
! 					(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
! 			Log_RotationAge = 0;
! 			Log_RotationSize = 0;
  		}
! 		pfree(filename);
! 		return;
  	}
  
! 	setvbuf(fh, NULL, LBF_MODE, 0);
  
  #ifdef WIN32
! 	_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
  #endif
  
! 	/* 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;
  }
  
  
--- 1041,1172 ----
  	 * postmaster because it ain't gonna work in the EXEC_BACKEND case.) So we
  	 * will always append in that situation, even though truncating would
  	 * usually be safe.
+ 	 *
+ 	 * For consistency, we treat CSV logs the same even though they aren't
+ 	 * opened in the postmaster.
  	 */
! 	if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
  	{
! 		if (Log_truncate_on_rotation && time_based_rotation &&
! 			last_file_name != NULL && strcmp(filename, last_file_name) != 0)
! 			fh = fopen(filename, "w");
! 		else
! 			fh = fopen(filename, "a");
  
! 		if (!fh)
  		{
+ 			int			saveerrno = errno;
+ 
  			ereport(LOG,
! 					(errcode_for_file_access(),
! 					 errmsg("could not open new log file \"%s\": %m",
! 							filename)));
! 
! 			/*
! 			 * 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 (saveerrno != ENFILE && saveerrno != EMFILE)
! 			{
! 				ereport(LOG,
! 						(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
! 				Log_RotationAge = 0;
! 				Log_RotationSize = 0;
! 			}
! 			pfree(filename);
! 			return;
  		}
! 
! 		setvbuf(fh, NULL, LBF_MODE, 0);
! 
! #ifdef WIN32
! 		_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
! #endif
! 
! 		/* On Windows, need to interlock against data-transfer thread */
! #ifdef WIN32
! 		EnterCriticalSection(&sysfileSection);
! #endif
! 		fclose(syslogFile);
! 		syslogFile = fh;
! #ifdef WIN32
! 		LeaveCriticalSection(&sysfileSection);
! #endif
! 
! 		/* instead of pfree'ing filename, remember it for next time */
! 		if (last_file_name != NULL)
! 			pfree(last_file_name);
! 		last_file_name = filename;
! 
! 
  	}
  
! 	/* same as above, but for csv file. */
! 
! 	if (csvlogFile != NULL && ( 
! 			time_based_rotation || 
! 			(size_rotation_for & LOG_DESTINATION_STDERR)))
! 	{
! 		if (Log_truncate_on_rotation && time_based_rotation &&
! 			last_csvfile_name != NULL && 
! 			strcmp(csvfilename, last_csvfile_name) != 0)
! 			
! 			fh = fopen(csvfilename, "w");
! 		else
! 			fh = fopen(csvfilename, "a");
! 
! 		if (!fh)
! 		{
! 			int			saveerrno = errno;
! 
! 			ereport(LOG,
! 					(errcode_for_file_access(),
! 					 errmsg("could not open new log file \"%s\": %m",
! 							csvfilename)));
! 
! 			/*
! 			 * 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 (saveerrno != ENFILE && saveerrno != EMFILE)
! 			{
! 				ereport(LOG,
! 						(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
! 				Log_RotationAge = 0;
! 				Log_RotationSize = 0;
! 			}
! 			pfree(csvfilename);
! 			return;
! 		}
! 
! 		setvbuf(fh, NULL, LBF_MODE, 0);
  
  #ifdef WIN32
! 		_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
  #endif
  
! 		/* On Windows, need to interlock against data-transfer thread */
  #ifdef WIN32
! 		EnterCriticalSection(&sysfileSection);
  #endif
! 		fclose(csvlogFile);
! 		syslogFile = fh;
  #ifdef WIN32
! 		LeaveCriticalSection(&sysfileSection);
  #endif
  
+ 		/* instead of pfree'ing filename, remember it for next time */
+ 		if (last_csvfile_name != NULL)
+ 			pfree(last_csvfile_name);
+ 		last_csvfile_name = filename;
+ 	}
+ 
  	set_next_rotation_time();
  
  }
  
  
***************
*** 1034,1040 ****
   * Result is palloc'd.
   */
  static char *
! logfile_getname(pg_time_t timestamp)
  {
  	char	   *filename;
  	int			len;
--- 1176,1182 ----
   * Result is palloc'd.
   */
  static char *
! logfile_getname(pg_time_t timestamp, char * suffix)
  {
  	char	   *filename;
  	int			len;
***************
*** 1058,1063 ****
--- 1200,1215 ----
  				 Log_filename, (unsigned long) timestamp);
  	}
  
+ 	if (suffix != NULL)
+ 	{
+ 		len = strlen(filename);
+ 		if (len > 4 && (strcmp(filename+(len-4),".log") == 0))
+ 		{
+ 			len -= 4;
+ 		}
+ 		strncpy(filename + len, suffix, MAXPGPATH - len);
+ 	}
+ 
  	return filename;
  }
  
Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/error/elog.c,v
retrieving revision 1.193
diff -c -r1.193 elog.c
*** src/backend/utils/error/elog.c	4 Aug 2007 19:29:25 -0000	1.193
--- src/backend/utils/error/elog.c	7 Aug 2007 12:25:30 -0000
***************
*** 104,109 ****
--- 104,117 ----
  
  static int	recursion_depth = 0;	/* to detect actual recursion */
  
+ /* buffers for formatted timestamps that might be used by both
+  * log_line_prefix and csv logs.
+  */
+ 
+ #define FORMATTED_TS_LEN 128
+ static char formatted_start_time[FORMATTED_TS_LEN];
+ static char formatted_log_time[FORMATTED_TS_LEN];
+ 
  
  /* Macro for checking errordata_stack_depth is reasonable */
  #define CHECK_STACK_DEPTH() \
***************
*** 124,131 ****
  static const char *error_severity(int elevel);
  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_pipe_chunks(int fd, char *data, int len);
! 
  
  /*
   * errstart --- begin an error-reporting cycle
--- 132,139 ----
  static const char *error_severity(int elevel);
  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_pipe_chunks(char *data, int len, int dest);
! static void get_error_message(StringInfo buf, ErrorData *edata);
  
  /*
   * errstart --- begin an error-reporting cycle
***************
*** 1434,1445 ****
  	/*
  	 * 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++;
  
--- 1442,1455 ----
  	/*
  	 * 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. MyStartTime also changes when MyProcPid does, so
! 	 * reset the formatted start timestamp too.
  	 */
  	if (log_my_pid != MyProcPid)
  	{
  		log_line_number = 0;
  		log_my_pid = MyProcPid;
+ 		formatted_start_time[0] = '\0';
  	}
  	log_line_number++;
  
***************
*** 1498,1505 ****
  					struct timeval tv;
  					pg_time_t	stamp_time;
  					pg_tz	   *tz;
! 					char		strfbuf[128],
! 								msbuf[8];
  
  					gettimeofday(&tv, NULL);
  					stamp_time = (pg_time_t) tv.tv_sec;
--- 1508,1514 ----
  					struct timeval tv;
  					pg_time_t	stamp_time;
  					pg_tz	   *tz;
! 					char		msbuf[8];
  
  					gettimeofday(&tv, NULL);
  					stamp_time = (pg_time_t) tv.tv_sec;
***************
*** 1512,1527 ****
  					 */
  					tz = log_timezone ? log_timezone : gmt_timezone;
  
! 					pg_strftime(strfbuf, sizeof(strfbuf),
  								/* leave room for milliseconds... */
  								"%Y-%m-%d %H:%M:%S     %Z",
  								pg_localtime(&stamp_time, tz));
  
  					/* 'paste' milliseconds into place... */
  					sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
! 					strncpy(strfbuf + 19, msbuf, 4);
  
! 					appendStringInfoString(buf, strfbuf);
  				}
  				break;
  			case 't':
--- 1521,1536 ----
  					 */
  					tz = log_timezone ? log_timezone : gmt_timezone;
  
! 					pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
  								/* leave room for milliseconds... */
  								"%Y-%m-%d %H:%M:%S     %Z",
  								pg_localtime(&stamp_time, tz));
  
  					/* 'paste' milliseconds into place... */
  					sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
! 					strncpy(formatted_log_time + 19, msbuf, 4);
  
! 					appendStringInfoString(buf, formatted_log_time);
  				}
  				break;
  			case 't':
***************
*** 1539,1556 ****
  				}
  				break;
  			case 's':
  				{
  					pg_time_t	stamp_time = (pg_time_t) MyStartTime;
  					pg_tz	   *tz;
- 					char		strfbuf[128];
  
  					tz = log_timezone ? log_timezone : gmt_timezone;
  
! 					pg_strftime(strfbuf, sizeof(strfbuf),
  								"%Y-%m-%d %H:%M:%S %Z",
  								pg_localtime(&stamp_time, tz));
- 					appendStringInfoString(buf, strfbuf);
  				}
  				break;
  			case 'i':
  				if (MyProcPort)
--- 1548,1565 ----
  				}
  				break;
  			case 's':
+ 				if (formatted_start_time[0] == '\0')
  				{
  					pg_time_t	stamp_time = (pg_time_t) MyStartTime;
  					pg_tz	   *tz;
  
  					tz = log_timezone ? log_timezone : gmt_timezone;
  
! 					pg_strftime(formatted_start_time, FORMATTED_TS_LEN,
  								"%Y-%m-%d %H:%M:%S %Z",
  								pg_localtime(&stamp_time, tz));
  				}
+ 				appendStringInfoString(buf, formatted_start_time);
  				break;
  			case 'i':
  				if (MyProcPort)
***************
*** 1596,1601 ****
--- 1605,1849 ----
  	}
  }
  
+ 
+ /*
+  * append a CSV'd version of a string to a StringInfo
+  * We use the PostgreSQL defaults for CSV, i.e. quote = escape = '"'
+  */
+ 
+ static inline void 
+ appendCSVLiteral(StringInfo buf, const char* data)
+ {
+   const char * p = data;
+   char c;
+ 
+   appendStringInfoCharMacro(buf, '"');
+   while ( (c = *p++) != '\0' )
+   {
+       if (c == '"')
+           appendStringInfoCharMacro(buf, '"');
+       appendStringInfoCharMacro(buf, c);
+   }
+   appendStringInfoCharMacro(buf, '"');
+ }
+ 
+ /* 
+  * 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)
+ {
+ 	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;
+ 		formatted_start_time[0] = '\0';
+     }
+     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 (formatted_log_time[0] == '\0')
+ 	{
+ 		struct timeval tv;
+ 		pg_time_t	stamp_time;
+ 		pg_tz	   *tz;
+ 		char		msbuf[8];
+ 		
+ 		gettimeofday(&tv, NULL);
+ 		stamp_time = (pg_time_t) tv.tv_sec;
+ 		
+ 		/*
+ 		 * Normally we print log timestamps in log_timezone, but
+ 		 * during startup we could get here before that's set.
+ 		 * If so, fall back to gmt_timezone (which guc.c ensures
+ 		 * is set up before Log_line_prefix can become nonempty).
+ 		 */
+ 		tz = log_timezone ? log_timezone : gmt_timezone;
+ 		
+ 		pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
+ 					/* leave room for milliseconds... */
+ 					"%Y-%m-%d %H:%M:%S     %Z",
+ 					pg_localtime(&stamp_time, tz));
+ 
+ 		/* 'paste' milliseconds into place... */
+ 		sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
+ 		strncpy(formatted_log_time + 19, msbuf, 4);
+ 	}
+ 	appendStringInfoString(&buf, formatted_log_time);
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* username */
+ 	if (MyProcPort)
+ 	{
+ 		const char *username = MyProcPort->user_name;
+ 		if (username == NULL || *username == '\0')
+ 			username = _("[unknown]");
+ 
+ 		appendCSVLiteral(&buf, username);
+ 	}
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* databasename */
+ 	if (MyProcPort)
+ 	{
+ 		const char *dbname = MyProcPort->database_name;
+ 
+ 		if (dbname == NULL || *dbname == '\0')
+ 			dbname = _("[unknown]");
+ 		
+ 		appendCSVLiteral(&buf, dbname);
+ 	}
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* session id */
+ 	appendStringInfo(&buf, "%lx.%x",
+ 					 (long) MyStartTime, MyProcPid);
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* Remote host and port */
+ 	if (MyProcPort && MyProcPort->remote_host)
+ 	{
+ 		appendStringInfo(&buf, "%s", MyProcPort->remote_host);
+ 		if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
+ 			appendStringInfo(&buf, ":%s", MyProcPort->remote_port);
+ 	}
+ 
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* Process id  */
+ 	if (MyProcPid != 0)
+ 		appendStringInfo(&buf, "%d", MyProcPid);
+ 
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* Line number */
+ 	appendStringInfo(&buf, "%ld", log_line_number);
+ 
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* PS display */
+ 	if (MyProcPort)
+ 	{
+ 		const char *psdisp;
+ 		int         displen;
+ 
+ 		psdisp = get_ps_display(&displen);
+ 		appendStringInfo(&msgbuf, "%.*s", displen, psdisp);
+ 		appendCSVLiteral(&buf, msgbuf.data);
+ 		resetStringInfo(&msgbuf);
+ 	}
+ 
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* session start timestamp */
+ 	if (formatted_start_time[0] == '\0')
+ 	{
+ 		pg_time_t	stamp_time = (pg_time_t) MyStartTime;
+ 		pg_tz	   *tz;
+ 					
+ 		tz = log_timezone ? log_timezone : gmt_timezone;
+ 
+ 		pg_strftime(formatted_start_time, FORMATTED_TS_LEN,
+ 					"%Y-%m-%d %H:%M:%S %Z",
+ 					pg_localtime(&stamp_time, tz));
+ 	}
+ 	appendStringInfoString(&buf, formatted_start_time);
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 
+ 	/* Transaction id */
+ 	if (MyProcPort)
+ 	{
+ 		if (IsTransactionState())
+ 			appendStringInfo(&buf, "%u", GetTopTransactionId());
+ 		else
+ 			appendStringInfo(&buf, "%u", InvalidTransactionId);
+ 	}
+ 
+ 	appendStringInfoChar(&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));
+ 	appendStringInfoChar(&buf, ',');
+  
+ 	/* Error message and cursor position if any */
+ 	get_error_message(&msgbuf, edata);
+ 
+ 	appendCSVLiteral(&buf, msgbuf.data);
+ 
+ 	appendStringInfoChar(&buf, '\n');
+ 
+ 	/* If in the syslogger process, try to write messages direct to file */
+ 	if (am_syslogger)
+ 		write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
+ 	else
+ 		write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG); 
+ 	
+ 	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)
+ {
+ 	if (edata->message)
+ 		appendStringInfo(buf, "%s", edata->message);
+ 	else
+ 		appendStringInfo(buf, "%s", _("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);
+ }
+ 
  /*
   * Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a
   * static buffer.
***************
*** 1627,1632 ****
--- 1875,1882 ----
  
  	initStringInfo(&buf);
  
+ 	formatted_log_time[0] = '\0';
+ 
  	log_line_prefix(&buf);
  	appendStringInfo(&buf, "%s:  ", error_severity(edata->elevel));
  
***************
*** 1766,1772 ****
  		 * syslogger.  Otherwise, just do a vanilla write to stderr.
  		 */
  		if (redirection_done && !am_syslogger)
! 			write_pipe_chunks(fileno(stderr), buf.data, buf.len);
  #ifdef WIN32
  		/*
  		 * In a win32 service environment, there is no usable stderr. Capture
--- 2016,2022 ----
  		 * syslogger.  Otherwise, just do a vanilla write to stderr.
  		 */
  		if (redirection_done && !am_syslogger)
! 			write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_STDERR);
  #ifdef WIN32
  		/*
  		 * In a win32 service environment, there is no usable stderr. Capture
***************
*** 1782,1790 ****
  			write(fileno(stderr), buf.data, buf.len);
  	}
  
  	/* 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);
  }
--- 2032,2062 ----
  			write(fileno(stderr), buf.data, buf.len);
  	}
  
+ 	if (Log_destination & LOG_DESTINATION_CSVLOG)
+ 	{
+ 		if (redirection_done || am_syslogger)
+ 		{
+ 			/* send CSV data if it's safe to do so (syslogger doesn't need
+ 			 * the pipe)
+ 			 */
+ 			write_csvlog(edata);
+ 		}
+ 		else
+ 		{
+ 			char * msg = _("Not safe to send CSV data\n");
+ 			write(fileno(stderr),msg,strlen(msg));
+ 			if ( ! (Log_destination & LOG_DESTINATION_STDERR) &&
+ 				 whereToSendOutput != DestDebug)
+ 			{
+ 				/* write message to stderr unless we just sent it above */
+ 				write(fileno(stderr), buf.data, buf.len);
+ 			}
+ 		}
+ 	}
+ 
  	/* If in the syslogger process, try to write messages direct to file */
  	if (am_syslogger)
! 		write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_STDERR);
  
  	pfree(buf.data);
  }
***************
*** 1793,1802 ****
   * Send data to the syslogger using the chunked protocol
   */
  static void
! write_pipe_chunks(int fd, char *data, int len)
  {
  	PipeProtoChunk p;
  
  	Assert(len > 0);
  
  	p.proto.nuls[0] = p.proto.nuls[1] = '\0';
--- 2065,2076 ----
   * Send data to the syslogger using the chunked protocol
   */
  static void
! write_pipe_chunks(char *data, int len, int dest)
  {
  	PipeProtoChunk p;
  
+ 	int fd = fileno(stderr);
+ 
  	Assert(len > 0);
  
  	p.proto.nuls[0] = p.proto.nuls[1] = '\0';
***************
*** 1805,1811 ****
  	/* write all but the last chunk */
  	while (len > PIPE_MAX_PAYLOAD)
  	{
! 		p.proto.is_last = 'f';
  		p.proto.len = PIPE_MAX_PAYLOAD;
  		memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD);
  		write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD);
--- 2079,2085 ----
  	/* write all but the last chunk */
  	while (len > PIPE_MAX_PAYLOAD)
  	{
! 		p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'F' : 'f');
  		p.proto.len = PIPE_MAX_PAYLOAD;
  		memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD);
  		write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD);
***************
*** 1814,1820 ****
  	}
  
  	/* write the last chunk */
! 	p.proto.is_last = 't';
  	p.proto.len = len;
  	memcpy(p.proto.data, data, len);
  	write(fd, &p, PIPE_HEADER_SIZE + len);
--- 2088,2094 ----
  	}
  
  	/* write the last chunk */
! 	p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'T' : 't');
  	p.proto.len = len;
  	memcpy(p.proto.data, data, len);
  	write(fd, &p, PIPE_HEADER_SIZE + len);
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v
retrieving revision 1.410
diff -c -r1.410 guc.c
*** src/backend/utils/misc/guc.c	4 Aug 2007 19:29:25 -0000	1.410
--- src/backend/utils/misc/guc.c	7 Aug 2007 12:25:35 -0000
***************
*** 2240,2246 ****
  		{"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
  		},
  		&log_destination_string,
--- 2240,2246 ----
  		{"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
  		},
  		&log_destination_string,
***************
*** 6312,6317 ****
--- 6312,6319 ----
  
  		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.223
diff -c -r1.223 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample	4 Aug 2007 01:26:54 -0000	1.223
--- src/backend/utils/misc/postgresql.conf.sample	7 Aug 2007 12:25:35 -0000
***************
*** 229,236 ****
  # - 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:
  #redirect_stderr = off			# Enable capturing of stderr into log 
--- 229,237 ----
  # - Where to Log -
  
  #log_destination = 'stderr'		# Valid values are combinations of 
! 					# stderr, csvlog, syslog and eventlog, 
  					# depending on platform.
+ 					# csvlog requires redirect_stderr to be on
  
  # This is used when logging to stderr:
  #redirect_stderr = off			# Enable capturing of stderr into log 
Index: src/include/postmaster/syslogger.h
===================================================================
RCS file: /cvsroot/pgsql/src/include/postmaster/syslogger.h,v
retrieving revision 1.10
diff -c -r1.10 syslogger.h
*** src/include/postmaster/syslogger.h	25 Jul 2007 12:22:53 -0000	1.10
--- src/include/postmaster/syslogger.h	7 Aug 2007 12:25:36 -0000
***************
*** 24,32 ****
   * also cope with non-protocol data coming down the pipe, though we cannot
   * guarantee long strings won't get split apart.
   *
!  * We use 't' or 'f' instead of a bool for is_last to make the protocol a tiny
!  * bit more robust against finding a false double nul byte prologue.  But we
!  * still might find it in the len and/or pid bytes unless we're careful.
   */
  
  #ifdef PIPE_BUF
--- 24,32 ----
   * also cope with non-protocol data coming down the pipe, though we cannot
   * guarantee long strings won't get split apart.
   *
!  * We use non-nul bytes in is_last to make the protocol a tiny bit 
!  * more robust against finding a false double nul byte prologue. But
!  * we still might find it in the len and/or pid bytes unless we're careful.
   */
  
  #ifdef PIPE_BUF
***************
*** 46,52 ****
  	char		nuls[2];		/* always \0\0 */
  	uint16		len;			/* size of this chunk (counts data only) */
  	int32		pid;			/* writer's pid */
! 	char		is_last;		/* last chunk of message? 't' or 'f' */
  	char		data[1];		/* data payload starts here */
  } PipeProtoHeader;
  
--- 46,54 ----
  	char		nuls[2];		/* always \0\0 */
  	uint16		len;			/* size of this chunk (counts data only) */
  	int32		pid;			/* writer's pid */
! 	char		is_last;		/* last chunk of message? 't' or 'f' 
! 	                             * ('T' or 'F' for CSV case)
! 								 */
  	char		data[1];		/* data payload starts here */
  } PipeProtoHeader;
  
***************
*** 79,85 ****
  
  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[]);
--- 81,87 ----
  
  extern int	SysLogger_Start(void);
  
! extern void write_syslogger_file(const char *buffer, int count, int dest);
  
  #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.87
diff -c -r1.87 elog.h
*** src/include/utils/elog.h	25 Jul 2007 12:22:54 -0000	1.87
--- src/include/utils/elog.h	7 Aug 2007 12:25:36 -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);
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

Reply via email to