Re: WIP CSV logs - Mailing list pgsql-patches
From | Andrew Dunstan |
---|---|
Subject | Re: WIP CSV logs |
Date | |
Msg-id | 46851BF8.6020005@dunslane.net Whole thread Raw |
In response to | Re: WIP CSV logs (Andrew Dunstan <andrew@dunslane.net>) |
Responses |
Re: WIP CSV logs
|
List | pgsql-patches |
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(¶m->syslogPipe, &syslogPipe, sizeof(syslogPipe)); + memcpy(¶m->csvlogPipe, &csvlogPipe, sizeof(csvlogPipe)); strlcpy(param->my_exec_path, my_exec_path, MAXPGPATH); *************** *** 4161,4166 **** --- 4175,4181 ---- #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.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);
pgsql-patches by date: