Andrew Dunstan wrote:


Andrew Dunstan wrote:

Here is a WIP patch of the CSV logs work brought up to date with CVS HEAD. One large change I made was to multiplex the selects on the pipes - previously it waited on one then the other - this seems almost to defeat the purpose of using select() :-)

It seems to work well on Unix - I will test later on Windows, which I'm slightly worried about.

I also want to get an id for non-session processes. I think this can just be start-time+pid, just like for session processes, but we'll need to stash it somewhere (just for those cases). If we do that we will be able to set a primary key on the log table when we read the data in, which Greg Smith was worried about.

I hope to get this polished off in the next 15 hours or so - after that I'm away for 12 days.



Here is a slightly updated version. It compiles on Windows, but it doesn't work - the CSV log file gets created but doesn't get any content. Dave, Magnus - can you see what I've done wrong? The strange thing is that I tried to do exactly the same thing for CSV as for stderr, and the stderr file gets content just fine.



Further update attached. Includes some code cleanup, and now sets up a session-id for all processes, including postmaster, syslogger etc, so we can make a primary key on the log table of (session_id, line_number).

TODOs: fix on Windows, docs.

cheers

andrew
Index: src/backend/postmaster/autovacuum.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/autovacuum.c,v
retrieving revision 1.51
diff -c -r1.51 autovacuum.c
*** src/backend/postmaster/autovacuum.c	25 Jun 2007 16:09:03 -0000	1.51
--- src/backend/postmaster/autovacuum.c	29 Jun 2007 14:33:40 -0000
***************
*** 386,391 ****
--- 386,393 ----
  	/* reset MyProcPid */
  	MyProcPid = getpid();
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  	/* Identify myself via ps */
  	init_ps_display("autovacuum launcher process", "", "", "");
  
***************
*** 1399,1404 ****
--- 1401,1408 ----
  	/* reset MyProcPid */
  	MyProcPid = getpid();
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  	/* Identify myself via ps */
  	init_ps_display("autovacuum worker process", "", "", "");
  
Index: src/backend/postmaster/pgarch.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/pgarch.c,v
retrieving revision 1.29
diff -c -r1.29 pgarch.c
*** src/backend/postmaster/pgarch.c	10 Feb 2007 14:58:54 -0000	1.29
--- src/backend/postmaster/pgarch.c	29 Jun 2007 14:33:40 -0000
***************
*** 223,228 ****
--- 223,230 ----
  
  	MyProcPid = getpid();		/* reset MyProcPid */
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  	/*
  	 * If possible, make this process a group leader, so that the postmaster
  	 * can signal any child processes too.
Index: src/backend/postmaster/pgstat.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/pgstat.c,v
retrieving revision 1.160
diff -c -r1.160 pgstat.c
*** src/backend/postmaster/pgstat.c	28 Jun 2007 00:02:38 -0000	1.160
--- src/backend/postmaster/pgstat.c	29 Jun 2007 14:33:42 -0000
***************
*** 2163,2168 ****
--- 2163,2170 ----
  
  	MyProcPid = getpid();		/* reset MyProcPid */
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  	/*
  	 * If possible, make this process a group leader, so that the postmaster
  	 * can signal any child processes too.  (pgstat probably never has
Index: src/backend/postmaster/postmaster.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/postmaster/postmaster.c,v
retrieving revision 1.528
diff -c -r1.528 postmaster.c
*** src/backend/postmaster/postmaster.c	25 Jun 2007 16:09:03 -0000	1.528
--- src/backend/postmaster/postmaster.c	29 Jun 2007 14:33:44 -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];
***************
*** 381,386 ****
--- 383,390 ----
  
  	MyProcPid = PostmasterPid = getpid();
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  	IsPostmasterEnvironment = true;
  
  	/*
***************
*** 1225,1231 ****
  		}
  
  		/* If we have lost the system logger, try to start a new one */
! 		if (SysLoggerPID == 0 && Redirect_stderr)
  			SysLoggerPID = SysLogger_Start();
  
  		/*
--- 1229,1236 ----
  		}
  
  		/* If we have lost the system logger, try to start a new one */
! 		if ( SysLoggerPID == 0 &&  
! 		     (Redirect_stderr || (Log_destination & LOG_DESTINATION_CSVLOG) ) )
  			SysLoggerPID = SysLogger_Start();
  
  		/*
***************
*** 1775,1784 ****
--- 1780,1797 ----
  		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
  	}
  }
***************
*** 3960,3965 ****
--- 3973,3979 ----
  #endif
  
  	memcpy(&param->syslogPipe, &syslogPipe, sizeof(syslogPipe));
+ 	memcpy(&param->csvlogPipe, &csvlogPipe, sizeof(csvlogPipe));
  
  	strlcpy(param->my_exec_path, my_exec_path, MAXPGPATH);
  
***************
*** 4161,4166 ****
--- 4175,4181 ----
  #endif
  
  	memcpy(&syslogPipe, &param->syslogPipe, sizeof(syslogPipe));
+ 	memcpy(&csvlogPipe, &param->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.32
diff -c -r1.32 syslogger.c
*** src/backend/postmaster/syslogger.c	14 Jun 2007 01:48:51 -0000	1.32
--- src/backend/postmaster/syslogger.c	29 Jun 2007 14:33:45 -0000
***************
*** 85,91 ****
  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;
  
  /* 
--- 85,91 ----
  static pg_time_t next_rotation_time;
  static bool redirection_done = false;
  static bool pipe_eof_seen = false;
! static FILE *syslogFile = NULL, *csvlogFile = NULL;
  static char *last_file_name = NULL;
  
  /* 
***************
*** 103,120 ****
  } save_buffer;
  
  #define CHUNK_SLOTS 20
! static save_buffer saved_chunks[CHUNK_SLOTS];
  
  /* 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
  
  /*
--- 103,123 ----
  } save_buffer;
  
  #define CHUNK_SLOTS 20
! static save_buffer stderr_saved_chunks[CHUNK_SLOTS]; 
! static save_buffer csvlog_saved_chunks[CHUNK_SLOTS];
  
  /* 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 stderrThreadHandle = 0, csvThreadHandle = 0;
! static CRITICAL_SECTION sysfileSection, csvfileSection;
  #endif
  
  /*
***************
*** 129,142 ****
  static pid_t syslogger_forkexec(void);
  static void syslogger_parseArgs(int argc, char *argv[]);
  #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);
--- 132,149 ----
  static pid_t syslogger_forkexec(void);
  static void syslogger_parseArgs(int argc, char *argv[]);
  #endif
! static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer,
! 							   int log_type);
! static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer,
! 							 int log_type);
  
  #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, int log_type);
! static void logfile_rotate_worker(bool overwrite_logfile, int log_type, 
! 								  char* filename, FILE **dest_file);
  static void set_next_rotation_time(void);
  static void sigHupHandler(SIGNAL_ARGS);
  static void sigUsr1Handler(SIGNAL_ARGS);
***************
*** 150,157 ****
  SysLoggerMain(int argc, char *argv[])
  {
  #ifndef WIN32
! 	char		logbuffer[READ_BUF_SIZE];
! 	int			bytes_in_logbuffer = 0;
  #endif
  	char	   *currentLogDir;
  	char	   *currentLogFilename;
--- 157,166 ----
  SysLoggerMain(int argc, char *argv[])
  {
  #ifndef WIN32
! 	char		stderr_logbuffer[READ_BUF_SIZE], csv_logbuffer[READ_BUF_SIZE];
! 	int			bytes_in_stderr_logbuffer = 0, bytes_in_csv_logbuffer = 0;
! 	int         maxfd = 0;
! 
  #endif
  	char	   *currentLogDir;
  	char	   *currentLogFilename;
***************
*** 161,166 ****
--- 170,177 ----
  
  	MyProcPid = getpid();		/* reset MyProcPid */
  
+ 	MyStartTime = time(NULL);       /* get start time for logger session id */
+ 
  #ifdef EXEC_BACKEND
  	syslogger_parseArgs(argc, argv);
  #endif   /* EXEC_BACKEND */
***************
*** 176,182 ****
  	 * 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);
  
--- 187,193 ----
  	 * 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);
  
***************
*** 202,211 ****
--- 213,239 ----
  	if (syslogPipe[1] >= 0)
  		close(syslogPipe[1]);
  	syslogPipe[1] = -1;
+ 	
+ 	if (csvlogPipe[1] >= 0)
+ 		close(csvlogPipe[1]);
+ 	csvlogPipe[1] = -1;
+ 
+ 	/* also set the max fd number for non-windows select use */
+ 	if (Redirect_stderr)
+ 		maxfd = syslogPipe[0];
+ 
+ 	if ((Log_destination & LOG_DESTINATION_CSVLOG) && 
+ 		(maxfd < csvlogPipe[0]))
+ 		maxfd = csvlogPipe[0];
+ 
  #else
  	if (syslogPipe[1])
  		CloseHandle(syslogPipe[1]);
  	syslogPipe[1] = 0;
+ 	
+ 	if (csvlogPipe[1])
+ 		CloseHandle(csvlogPipe[1]);
+ 	csvlogPipe[1] = 0;
  #endif
  
  	/*
***************
*** 248,260 ****
  	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 */
  
--- 276,301 ----
  	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);
+ 		stderrThreadHandle = (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);
! 		csvThreadHandle = (HANDLE) _beginthreadex(0, 0, pipeThread, 
! 								&logtype, 0, &tid);
  	}
  #endif   /* WIN32 */
  
***************
*** 275,280 ****
--- 316,322 ----
  		int			rc;
  		fd_set		rfds;
  		struct timeval timeout;
+ 
  #endif
  
  		if (got_SIGHUP)
***************
*** 336,346 ****
  		 * 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)
  		{
--- 378,391 ----
  		 * Wait for some data, timing out after 1 second
  		 */
  		FD_ZERO(&rfds);
! 		if (Redirect_stderr)
! 			FD_SET(syslogPipe[0], &rfds);
! 		if (Log_destination & LOG_DESTINATION_CSVLOG)
! 			FD_SET(csvlogPipe[0], &rfds);
  		timeout.tv_sec = 1;
  		timeout.tv_usec = 0;
  
! 		rc = select(maxfd + 1, &rfds, NULL, NULL, &timeout);
  
  		if (rc < 0)
  		{
***************
*** 349,384 ****
  						(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 + bytes_in_logbuffer,
! 								 sizeof(logbuffer) - bytes_in_logbuffer);
! 			if (bytesRead < 0)
  			{
! 				if (errno != EINTR)
! 					ereport(LOG,
! 							(errcode_for_socket_access(),
! 							 errmsg("could not read from logger pipe: %m")));
! 			}
! 			else if (bytesRead > 0)
! 			{
! 				bytes_in_logbuffer += bytesRead;
! 				process_pipe_input(logbuffer, &bytes_in_logbuffer);
! 				continue;
  			}
! 			else
  			{
! 				/*
! 				 * Zero bytes read when select() is saying read-ready means
! 				 * EOF on the pipe: that is, there are no longer any processes
! 				 * with the pipe write end open.  Therefore, the postmaster
! 				 * and all backends are shut down, and we are done.
! 				 */
! 				pipe_eof_seen = true;
  
! 				/* if there's any data left then force it out now */
! 				flush_pipe_input(logbuffer, &bytes_in_logbuffer);
  			}
  		}
  #else							/* WIN32 */
--- 394,460 ----
  						(errcode_for_socket_access(),
  						 errmsg("select() failed in logger process: %m")));
  		}
! 		else if (rc > 0)
  		{
! 			if (Redirect_stderr && FD_ISSET(syslogPipe[0], &rfds))
  			{
! 				bytesRead = piperead(syslogPipe[0],
! 							 stderr_logbuffer + bytes_in_stderr_logbuffer,
! 							 sizeof(stderr_logbuffer) - bytes_in_stderr_logbuffer);
! 				if (bytesRead < 0)
! 				{
!                 if (errno != EINTR)
!                     ereport(LOG,
!                             (errcode_for_socket_access(),
!                              errmsg("could not read from stderr logger pipe: %m")));
! 				}
! 				else if (bytesRead > 0)
! 				{
! 					bytes_in_stderr_logbuffer += bytesRead;
! 					process_pipe_input(stderr_logbuffer, 
! 									   &bytes_in_stderr_logbuffer, 
! 									   STDERR_LOGFILE);
! 					continue;
! 				}
! 				else
! 				{
! 					/*
! 					 * Zero bytes read when select() is saying read-ready means
! 					 * EOF on the pipe: that is, there are no longer any processes
! 					 * with the pipe write end open.  Therefore, the postmaster
! 					 * and all backends are shut down, and we are done.
! 					 */
! 					pipe_eof_seen = true;
! 
! 				}
  			}
! 
! 			if ((Log_destination & LOG_DESTINATION_CSVLOG) && 
! 				FD_ISSET(csvlogPipe[0], &rfds))
  			{
! 				bytesRead = piperead(csvlogPipe[0],
! 							 csv_logbuffer + bytes_in_csv_logbuffer,
! 							 sizeof(csv_logbuffer) - bytes_in_csv_logbuffer);
! 				if (bytesRead < 0)
! 				{
!                 if (errno != EINTR)
!                     ereport(LOG,
!                             (errcode_for_socket_access(),
!                              errmsg("could not read from CSV logger pipe: %m")));
! 				}
! 				else if (bytesRead > 0)
! 				{
! 					bytes_in_csv_logbuffer += bytesRead;
! 					process_pipe_input(csv_logbuffer, 
! 									   &bytes_in_csv_logbuffer, 
! 									   CSV_LOGFILE);
! 					continue;
! 				}
! 				else
! 				{
! 					pipe_eof_seen = true;
  
! 				}
  			}
  		}
  #else							/* WIN32 */
***************
*** 393,398 ****
--- 469,484 ----
  
  		if (pipe_eof_seen)
  		{
+ 
+ #ifndef WIN32
+ 			/* if there's any data left then force it out now */
+ 			if (Redirect_stderr)
+ 				flush_pipe_input(stderr_logbuffer, &bytes_in_stderr_logbuffer, STDERR_LOGFILE);
+ 
+ 			if (Log_destination & LOG_DESTINATION_CSVLOG)
+ 				flush_pipe_input(csv_logbuffer, &bytes_in_csv_logbuffer, CSV_LOGFILE);
+ 
+ #endif
  			ereport(LOG,
  					(errmsg("logger shutting down")));
  
***************
*** 414,423 ****
  int
  SysLogger_Start(void)
  {
  	pid_t		sysloggerPid;
- 	char	   *filename;
  
! 	if (!Redirect_stderr)
  		return 0;
  
  	/*
--- 500,511 ----
  int
  SysLogger_Start(void)
  {
+ 	char	*csv_filename;
+ 	char	*stderr_filename;
+ 
  	pid_t		sysloggerPid;
  
! 	if ( (!Redirect_stderr) && (!(Log_destination & LOG_DESTINATION_CSVLOG)) )
  		return 0;
  
  	/*
***************
*** 432,460 ****
  	 * 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
--- 520,581 ----
  	 * 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
***************
*** 465,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");
  
! 	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()))
--- 586,622 ----
  	 * 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()))
***************
*** 511,517 ****
  			/* success, in postmaster */
  
  			/* now we redirect stderr, if not done already */
! 			if (!redirection_done)
  			{
  #ifndef WIN32
  				fflush(stdout);
--- 650,656 ----
  			/* success, in postmaster */
  
  			/* now we redirect stderr, if not done already */
! 			if (Redirect_stderr && !redirection_done)
  			{
  #ifndef WIN32
  				fflush(stdout);
***************
*** 545,553 ****
  				redirection_done = true;
  			}
  
! 			/* postmaster will never write the file; close it */
! 			fclose(syslogFile);
  			syslogFile = NULL;
  			return (int) sysloggerPid;
  	}
  
--- 684,698 ----
  				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;
  	}
  
***************
*** 566,576 ****
  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";
--- 711,721 ----
  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";
***************
*** 583,588 ****
--- 728,738 ----
  	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",
***************
*** 590,595 ****
--- 740,751 ----
  	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 */
***************
*** 613,619 ****
  {
  	int			fd;
  
! 	Assert(argc == 5);
  	argv += 3;
  
  #ifndef WIN32
--- 769,775 ----
  {
  	int			fd;
  
! 	Assert(argc == 6);
  	argv += 3;
  
  #ifndef WIN32
***************
*** 624,629 ****
--- 780,792 ----
  		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)
***************
*** 636,641 ****
--- 799,815 ----
  		}
  	}
  	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 */
***************
*** 670,679 ****
   * logbuffer, and *bytes_in_logbuffer is updated.
   */
  static void
! process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
  {
  	char   *cursor = logbuffer;
  	int		count = *bytes_in_logbuffer;
  
  	/* While we have enough for a header, process data... */
  	while (count >= (int) sizeof(PipeProtoHeader))
--- 844,859 ----
   * logbuffer, and *bytes_in_logbuffer is updated.
   */
  static void
! process_pipe_input(char *logbuffer, int *bytes_in_logbuffer, int log_type)
  {
  	char   *cursor = logbuffer;
  	int		count = *bytes_in_logbuffer;
+ 	save_buffer *saved_chunks;
+ 
+ 	saved_chunks = log_type == CSV_LOGFILE ? 
+ 		csvlog_saved_chunks :
+ 		stderr_saved_chunks;
+ 		
  
  	/* While we have enough for a header, process data... */
  	while (count >= (int) sizeof(PipeProtoHeader))
***************
*** 737,743 ****
  					 * 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
--- 917,923 ----
  					 * 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, log_type);
  				}
  			}
  			else
***************
*** 764,777 ****
  					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);
  				}
  			}
  
--- 944,957 ----
  					appendBinaryStringInfo(str,
  										   cursor + PIPE_HEADER_SIZE,
  										   p.len);
! 					write_syslogger_file(str->data, str->len, log_type);
  					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, log_type);
  				}
  			}
  
***************
*** 797,803 ****
  				if (cursor[chunklen] == '\0')
  					break;
  			}
! 			write_syslogger_file(cursor, chunklen);
  			cursor += chunklen;
  			count -= chunklen;
  		}
--- 977,983 ----
  				if (cursor[chunklen] == '\0')
  					break;
  			}
! 			write_syslogger_file(cursor, chunklen, log_type);
  			cursor += chunklen;
  			count -= chunklen;
  		}
***************
*** 816,825 ****
   * useful at other times, so it is careful to leave things in a clean state.
   */
  static void
! flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
  {
  	int i;
  	StringInfo str;
  
  	/* Dump any incomplete protocol messages */
  	for (i = 0; i < CHUNK_SLOTS; i++)
--- 996,1011 ----
   * useful at other times, so it is careful to leave things in a clean state.
   */
  static void
! flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer, int log_type)
  {
  	int i;
  	StringInfo str;
+ 	save_buffer *saved_chunks;
+ 
+ 	saved_chunks = log_type == CSV_LOGFILE ? 
+ 		csvlog_saved_chunks :
+ 		stderr_saved_chunks;
+ 		
  
  	/* Dump any incomplete protocol messages */
  	for (i = 0; i < CHUNK_SLOTS; i++)
***************
*** 827,833 ****
  		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);
  		}
--- 1013,1019 ----
  		if (saved_chunks[i].pid != 0)
  		{
  			str = &(saved_chunks[i].data);
! 			write_syslogger_file(str->data, str->len, log_type);
  			saved_chunks[i].pid = 0;
  			pfree(str->data);
  		}
***************
*** 837,852 ****
  	 * 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;
  }
  
  
- /* --------------------------------
-  *		logfile routines
-  * --------------------------------
-  */
- 
  /*
   * Write text to the currently open logfile
   *
--- 1023,1033 ----
  	 * remove any protocol headers that may exist in it.
  	 */
  	if (*bytes_in_logbuffer > 0)
! 		write_syslogger_file(logbuffer, *bytes_in_logbuffer, log_type);
  	*bytes_in_logbuffer = 0;
  }
  
  
  /*
   * Write text to the currently open logfile
   *
***************
*** 855,870 ****
   * 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 */
--- 1036,1074 ----
   * 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;
! 
! 	/* Select the file to write to based on the log_type. */
! 	switch (log_type)
! 	{
! 		case STDERR_LOGFILE:
! 			fh = (FILE **) &syslogFile;
! 			break;
! 		case CSV_LOGFILE:
! 			fh = (FILE **) &csvlogFile;
! 			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 */
***************
*** 884,897 ****
  static unsigned int __stdcall
  pipeThread(void *arg)
  {
  	char		logbuffer[READ_BUF_SIZE];
  	int			bytes_in_logbuffer = 0;
  
  	for (;;)
  	{
  		DWORD		bytesRead;
  
! 		if (!ReadFile(syslogPipe[0],
  					  logbuffer + bytes_in_logbuffer,
  					  sizeof(logbuffer) - bytes_in_logbuffer,
  					  &bytesRead, 0))
--- 1088,1109 ----
  static unsigned int __stdcall
  pipeThread(void *arg)
  {
+ 
+ 	int         log_type = *(int *)arg;
  	char		logbuffer[READ_BUF_SIZE];
  	int			bytes_in_logbuffer = 0;
+ 	HANDLE      logpipe;
+ 
+ 	if (log_type == CSV_LOGFILE)
+ 		logpipe = csvlogPipe[0];
+ 	else
+ 		logpipe = syslogPipe[0];
  
  	for (;;)
  	{
  		DWORD		bytesRead;
  
! 		if (!ReadFile(logpipe,
  					  logbuffer + bytes_in_logbuffer,
  					  sizeof(logbuffer) - bytes_in_logbuffer,
  					  &bytesRead, 0))
***************
*** 909,915 ****
  		else if (bytesRead > 0)
  		{
  			bytes_in_logbuffer += bytesRead;
! 			process_pipe_input(logbuffer, &bytes_in_logbuffer);
  		}
  	}
  
--- 1121,1127 ----
  		else if (bytesRead > 0)
  		{
  			bytes_in_logbuffer += bytesRead;
! 			process_pipe_input(logbuffer, &bytes_in_logbuffer, log_type);
  		}
  	}
  
***************
*** 917,949 ****
  	pipe_eof_seen = true;
  
  	/* if there's any data left then force it out now */
! 	flush_pipe_input(logbuffer, &bytes_in_logbuffer);
  
  	_endthread();
  	return 0;
  }
  #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)
--- 1129,1169 ----
  	pipe_eof_seen = true;
  
  	/* if there's any data left then force it out now */
! 	flush_pipe_input(logbuffer, &bytes_in_logbuffer, log_type);
  
  	_endthread();
  	return 0;
  }
  #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)
***************
*** 959,964 ****
--- 1179,1214 ----
  	 */
  	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");
***************
*** 993,1022 ****
  
  	/* 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;
--- 1243,1272 ----
  
  	/* 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;
***************
*** 1041,1046 ****
--- 1291,1303 ----
  				 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.187
diff -c -r1.187 elog.c
*** src/backend/utils/error/elog.c	14 Jun 2007 01:48:51 -0000	1.187
--- src/backend/utils/error/elog.c	29 Jun 2007 14:33:47 -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 */
***************
*** 126,131 ****
--- 128,136 ----
  static bool is_log_level_output(int elevel, int log_min_level);
  static void write_pipe_chunks(int fd, char *data, int len);
  
+ static void write_csvlog(ErrorData *edata);
+ static void get_error_message(StringInfo buf, ErrorData *edata);
+ static void get_timestamp(StringInfo buf);
  
  /*
   * errstart --- begin an error-reporting cycle
***************
*** 1494,1534 ****
  				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':
  				{
***************
*** 1635,1640 ****
--- 1606,1612 ----
  {
  	StringInfoData buf;
  
+ 	memset(timestamp, '\0', sizeof(timestamp));
  	initStringInfo(&buf);
  
  	log_line_prefix(&buf);
***************
*** 1643,1659 ****
  	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');
  
--- 1615,1622 ----
  	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');
  
***************
*** 1768,1774 ****
  #endif   /* WIN32 */
  
  	/* Write to stderr, if enabled */
! 	if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug)
  	{
  #ifdef WIN32
  
--- 1731,1738 ----
  #endif   /* WIN32 */
  
  	/* Write to stderr, if enabled */
! 	if ((Log_destination & LOG_DESTINATION_STDERR) || 
! 		whereToSendOutput == DestDebug)
  	{
  #ifdef WIN32
  
***************
*** 1780,1786 ****
  		 * 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
--- 1744,1751 ----
  		 * 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
***************
*** 1789,1798 ****
  			else
  				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);
  }
--- 1754,1767 ----
  			else
  				write(fileno(stderr), buf.data, buf.len);
  	}
!  
! 	/* Output log in csv format, if enabled */
! 	if(Log_destination & LOG_DESTINATION_CSVLOG) 
! 		write_csvlog(edata);
!  
  	/* If in the syslogger process, try to write messages direct to file */
  	if (am_syslogger)
! 		write_syslogger_file(buf.data, buf.len, STDERR_LOGFILE);
  
  	pfree(buf.data);
  }
***************
*** 2204,2206 ****
--- 2173,2448 ----
  
  	return false;
  }
+ 
+ 
+ /*
+  * 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;
+     }
+     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);
+ 
+ 	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 */
+ 	if (MyProcPort)
+ 	{
+ 		appendStringInfo(&buf, "%lx.%x",
+ 				 (long) (MyProcPort->session_start), MyProcPid);
+ 	}
+ 	else
+ 	{
+ 		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, ',');
+ 
+ 	/* Command tag */
+ 	if (MyProcPort)
+ 	{
+ 		const char *psdisp;
+ 		int			displen;
+ 
+ 		psdisp = get_ps_display(&displen);
+ 		appendStringInfo(&buf, "%.*s", displen, psdisp);
+ 	}
+ 
+ 	appendStringInfoChar(&buf, ',');
+ 
+ 	/* session start timestamp */
+ 	if (MyProcPort)
+ 	{
+ 		char		strfbuf[128];
+ 
+ 		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);
+ 	}
+ 
+ 
+ 	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, CSV_LOGFILE);
+ 	else
+ 	    write_pipe_chunks(csvlogPipe[1], buf.data, buf.len);
+ 
+ 	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);
+ }
+ 
Index: src/backend/utils/init/globals.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/init/globals.c,v
retrieving revision 1.101
diff -c -r1.101 globals.c
*** src/backend/utils/init/globals.c	16 Apr 2007 18:29:54 -0000	1.101
--- src/backend/utils/init/globals.c	29 Jun 2007 14:33:47 -0000
***************
*** 33,38 ****
--- 33,39 ----
  volatile uint32 CritSectionCount = 0;
  
  int			MyProcPid;
+ time_t			MyStartTime;
  struct Port *MyProcPort;
  long		MyCancelKey;
  
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v
retrieving revision 1.403
diff -c -r1.403 guc.c
*** src/backend/utils/misc/guc.c	28 Jun 2007 00:02:39 -0000	1.403
--- src/backend/utils/misc/guc.c	29 Jun 2007 14:33:51 -0000
***************
*** 2203,2209 ****
  	{
  		{"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
  		},
--- 2203,2209 ----
  	{
  		{"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
  		},
***************
*** 6270,6275 ****
--- 6270,6277 ----
  
  		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.217
diff -c -r1.217 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample	28 Jun 2007 00:02:39 -0000	1.217
--- src/backend/utils/misc/postgresql.conf.sample	29 Jun 2007 14:33:51 -0000
***************
*** 226,232 ****
  # - 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:
--- 226,232 ----
  # - 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:
***************
*** 234,240 ****
  					# 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.
--- 234,240 ----
  					# 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/miscadmin.h
===================================================================
RCS file: /cvsroot/pgsql/src/include/miscadmin.h,v
retrieving revision 1.194
diff -c -r1.194 miscadmin.h
*** src/include/miscadmin.h	16 Apr 2007 18:29:56 -0000	1.194
--- src/include/miscadmin.h	29 Jun 2007 14:33:52 -0000
***************
*** 132,137 ****
--- 132,138 ----
  extern int	MaxConnections;
  
  extern DLLIMPORT int MyProcPid;
+ extern DLLIMPORT time_t MyStartTime;
  extern DLLIMPORT struct Port *MyProcPort;
  extern long MyCancelKey;
  
Index: src/include/postmaster/syslogger.h
===================================================================
RCS file: /cvsroot/pgsql/src/include/postmaster/syslogger.h,v
retrieving revision 1.9
diff -c -r1.9 syslogger.h
*** src/include/postmaster/syslogger.h	14 Jun 2007 01:48:51 -0000	1.9
--- src/include/postmaster/syslogger.h	29 Jun 2007 14:33:52 -0000
***************
*** 60,65 ****
--- 60,71 ----
  #define PIPE_MAX_PAYLOAD  ((int) (PIPE_CHUNK_SIZE - PIPE_HEADER_SIZE))
  
  
+ #define LOG_BUFFER_SIZE	32768
+ 
+ #define STDERR_LOGFILE	1
+ #define CSV_LOGFILE	2
+ 
+ 
  /* GUC options */
  extern bool Redirect_stderr;
  extern int	Log_RotationAge;
***************
*** 72,85 ****
  
  #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[]);
--- 78,93 ----
  
  #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	29 Jun 2007 14:33:53 -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 7: You can help support the PostgreSQL project by donating at

                http://www.postgresql.org/about/donate

Reply via email to