rdelaage
/
postgresql
mirror of https://git.postgresql.org/git/postgresql.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Provide for logfiles in machine readable CSV format. In consequence, rename 

redirect_stderr to logging_collector.
Original patch from Arul Shaji, subsequently modified by Greg Smith, and then
heavily modified by me.
This commit is contained in:
Andrew Dunstan 2007-08-19 01:41:25 +00:00
parent e53a548794
commit fd801f4faa
12 changed files with 663 additions and 127 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

139
doc/src/sgml/config.sgml
View File

@ -1,4 +1,4 @@
<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.137 2007/08/13 19:27:11 tgl Exp $ -->
<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.138 2007/08/19 01:41:23 adunstan Exp $ -->
<chapter Id="runtime-config">
<title>Server Configuration</title>
@ -2261,7 +2261,7 @@ SELECT * FROM parent WHERE key = 2400;
<para>
<productname>PostgreSQL</productname> supports several methods
for logging server messages, including
<systemitem>stderr</systemitem> and
<systemitem>stderr</systemitem>, <systemitem>csvlog</systemitem> and
<systemitem>syslog</systemitem>. On Windows,
<systemitem>eventlog</systemitem> is also supported. Set this
parameter to a list of desired log destinations separated by
@ -2270,17 +2270,24 @@ SELECT * FROM parent WHERE key = 2400;
This parameter can only be set in the <filename>postgresql.conf</>
file or on the server command line.
</para>
<para> If <varname>log_destination</> is set to <systemitem>csvlog</systemitem>,
the log is output as comma seperated values. The format is:
timestamp with milliseconds, username, database name, session id, host:port number,
process id, per process line number, command tag, session start time, transaction id,
error severity, SQL state code, statement/error message.
</para>
</listitem>
</varlistentry>
<varlistentry id="guc-redirect-stderr" xreflabel="redirect_stderr">
<term><varname>redirect_stderr</varname> (<type>boolean</type>)</term>
<varlistentry id="guc-logging-collector" xreflabel="logging_collector">
<term><varname>logging_collector</varname> (<type>boolean</type>)</term>
<indexterm>
<primary><varname>redirect_stderr</> configuration parameter</primary>
<primary><varname>logging_collector</> configuration parameter</primary>
</indexterm>
<listitem>
<para>
This parameter allows messages sent to <application>stderr</> to be
This parameter allows messages sent to <application>stderr</>,
and CSV logs, to be
captured and redirected into log files.
This method, in combination with logging to <application>stderr</>,
is often more useful than
@ -2288,6 +2295,8 @@ SELECT * FROM parent WHERE key = 2400;
might not appear in <application>syslog</> output (a common example
is dynamic-linker failure messages).
This parameter can only be set at server start.
<varname>start_log_collector</varname> must be enabled to generate
CSV logs.
</para>
</listitem>
</varlistentry>
@ -2299,8 +2308,8 @@ SELECT * FROM parent WHERE key = 2400;
</indexterm>
<listitem>
<para>
When <varname>redirect_stderr</> is enabled, this parameter
determines the directory in which log files will be created.
When <varname>logging_collector</> is enabled,
this parameter determines the directory in which log files will be created.
It can be specified as an absolute path, or relative to the
cluster data directory.
This parameter can only be set in the <filename>postgresql.conf</>
@ -2316,8 +2325,8 @@ SELECT * FROM parent WHERE key = 2400;
</indexterm>
<listitem>
<para>
When <varname>redirect_stderr</varname> is enabled, this parameter
sets the file names of the created log files. The value
When <varname>logging_collector</varname> is enabled,
this parameter sets the file names of the created log files. The value
is treated as a <systemitem>strftime</systemitem> pattern,
so <literal>%</literal>-escapes can be used to specify time-varying
file names. (Note that if there are
@ -2332,6 +2341,14 @@ SELECT * FROM parent WHERE key = 2400;
This parameter can only be set in the <filename>postgresql.conf</>
file or on the server command line.
</para>
<para>
If <varname>log_destination</> is set to <systemitem>csvlog</>,
<literal>.csv</> will be appended to the timestamped
<varname>log_filename</> to create the final log file name.
(If log_filename ends in <literal>.log</>, the suffix is overwritten.)
In the case of the example above, the
file name will be <literal>server_log.1093827753.csv</literal>
</para>
</listitem>
</varlistentry>
@ -2342,8 +2359,8 @@ SELECT * FROM parent WHERE key = 2400;
</indexterm>
<listitem>
<para>
When <varname>redirect_stderr</varname> is enabled, this parameter
determines the maximum lifetime of an individual log file.
When <varname>logging_collector</varname> is enabled,
this parameter determines the maximum lifetime of an individual log file.
After this many minutes have elapsed, a new log file will
be created. Set to zero to disable time-based creation of
new log files.
@ -2360,8 +2377,8 @@ SELECT * FROM parent WHERE key = 2400;
</indexterm>
<listitem>
<para>
When <varname>redirect_stderr</varname> is enabled, this parameter
determines the maximum size of an individual log file.
When <varname>logging_collector</varname> is enabled,
this parameter determines the maximum size of an individual log file.
After this many kilobytes have been emitted into a log file,
a new log file will be created. Set to zero to disable size-based
creation of new log files.
@ -2378,8 +2395,8 @@ SELECT * FROM parent WHERE key = 2400;
</indexterm>
<listitem>
<para>
When <varname>redirect_stderr</varname> is enabled, this parameter will cause
<productname>PostgreSQL</productname> to truncate (overwrite),
When <varname>logging_collector</varname> is enabled,
this parameter will cause <productname>PostgreSQL</productname> to truncate (overwrite),
rather than append to, any existing log file of the same name.
However, truncation will occur only when a new file is being opened
due to time-based rotation, not during server startup or size-based
@ -2599,7 +2616,7 @@ SELECT * FROM parent WHERE key = 2400;
The server's standard output and standard error are redirected
to <literal>/dev/null</>, so any messages sent to them will be lost.
Unless <application>syslog</> logging is selected or
<varname>redirect_stderr</> is enabled, using this parameter
<varname>start_log_collector</> is enabled, using this parameter
is discouraged because it makes it impossible to see error messages.
This parameter can only be set at server start.
</para>
@ -3066,6 +3083,94 @@ SELECT * FROM parent WHERE key = 2400;
</varlistentry>
</variablelist>
</sect2>
<sect2 id="runtime-config-logging-csvlog">
<title>Using the csvlog</title>
<para>
Including <literal>csvlog</> in the <varname>log_destination</> list
provides a convenient way to import log files into a database table.
Here is a sample table definition for storing csvlog output:
</para>
<programlisting>
CREATE TABLE postgres_log
(
log_time timestamp,
username text,
database_name text,
sessionid text not null,
connection_from text,
process_id text,
process_line_num int not null,
command_tag text,
session_start_time timestamp,
transaction_id int,
error_severity text,
sql_state_code text,
statement text,
PRIMARY KEY (sessionid, process_line_num)
);
</programlisting>
<para>
In order to import into this table, use the COPY FROM command:
</para>
<programlisting>
COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
</programlisting>
<para>
There are a few things you need to import csvlog files easily and
automatically:
<orderedlist>
<listitem>
<para>
Use a consistant, predictable naming scheme for your log files
with <varname>log_filename</varname>. This lets you predict what
the file name will be when it is ready to be imported.
guess what
the file name will be and know when an individual log file is
complete and therefore ready to be imported.
</para>
</listitem>
<listitem>
<para>
Set <varname>log_rotation_size</varname> to 0 to disable
size-based log rotation, as it makes the log filename difficult
to predict.
</para>
</listitem>
<listitem>
<para>
Set <varname>log_truncate_on_rotate</varname> = on so that old
log data isn't mixed with the new in the same file.
</para>
</listitem>
<listitem>
<para>
The example above includes a useful primary key on the log
file data, which will protect against accidentally importing
the same information twice. The COPY command commits all of
the data it imports at one time, and any single error will
cause the entire import to fail.
If you import a partial log file and later import the file again
when it is complete, the primary key violation will cause the
import to fail. Wait until the log is complete and closed before
import. This will also protect against accidently importing a
partial line that hasn't been completely written, which would
also cause the COPY to fail.
</para>
</listitem>
</orderedlist>
</para>
</sect2>
</sect1>

8
doc/src/sgml/func.sgml
View File

@ -1,4 +1,4 @@
<!-- $PostgreSQL: pgsql/doc/src/sgml/func.sgml,v 1.385 2007/08/13 01:18:47 tgl Exp $ -->
<!-- $PostgreSQL: pgsql/doc/src/sgml/func.sgml,v 1.386 2007/08/19 01:41:23 adunstan Exp $ -->
<chapter id="functions">
<title>Functions and Operators</title>
@ -11254,9 +11254,9 @@ SELECT set_config('log_statement_stats', 'off', false);
<para>
<function>pg_rotate_logfile</> signals the log-file manager to switch
to a new output file immediately. This works only when
<varname>redirect_stderr</> is used for logging, since otherwise there
is no log-file manager subprocess.
to a new output file immediately. This works only when the built-in
log collector if running, since otherwise there is no log-file manager
subprocess.
</para>
<indexterm zone="functions-admin">

7
doc/src/sgml/maintenance.sgml
View File

@ -1,4 +1,4 @@
<!-- $PostgreSQL: pgsql/doc/src/sgml/maintenance.sgml,v 1.77 2007/07/23 17:22:00 alvherre Exp $ -->
<!-- $PostgreSQL: pgsql/doc/src/sgml/maintenance.sgml,v 1.78 2007/08/19 01:41:24 adunstan Exp $ -->
<chapter id="maintenance">
<title>Routine Database Maintenance Tasks</title>
@ -691,10 +691,11 @@ analyze threshold = analyze base threshold + analyze scale factor * number of tu
A better approach is to send the server's
<systemitem>stderr</> output to some type of log rotation program.
There is a built-in log rotation program, which you can use by
setting the configuration parameter <literal>redirect_stderr</> to
setting the configuration parameter <literal>logging_collector</> to
<literal>true</> in <filename>postgresql.conf</>. The control
parameters for this program are described in <xref
linkend="runtime-config-logging-where">.
linkend="runtime-config-logging-where">. You can also use this approach
to capture the log data in machine readable CSV format.
</para>
<para>

6
src/backend/postmaster/postmaster.c
View File

@ -37,7 +37,7 @@
*
*
* IDENTIFICATION
* $PostgreSQL: pgsql/src/backend/postmaster/postmaster.c,v 1.540 2007/08/09 01:18:43 tgl Exp $
* $PostgreSQL: pgsql/src/backend/postmaster/postmaster.c,v 1.541 2007/08/19 01:41:24 adunstan Exp $
*
* NOTES
*
@ -1282,8 +1282,8 @@ ServerLoop(void)
}
}
/* If we have lost the system logger, try to start a new one */
if (SysLoggerPID == 0 && Redirect_stderr)
/* If we have lost the log collector, try to start a new one */
if (SysLoggerPID == 0 && Logging_collector)
SysLoggerPID = SysLogger_Start();
/*

272
src/backend/postmaster/syslogger.c
View File

@ -18,7 +18,7 @@
*
*
* IDENTIFICATION
* $PostgreSQL: pgsql/src/backend/postmaster/syslogger.c,v 1.36 2007/08/04 01:26:53 tgl Exp $
* $PostgreSQL: pgsql/src/backend/postmaster/syslogger.c,v 1.37 2007/08/19 01:41:24 adunstan Exp $
*
*-------------------------------------------------------------------------
*/
@ -64,10 +64,10 @@
/*
* GUC parameters. Redirect_stderr cannot be changed after postmaster
* GUC parameters. Logging_collector cannot be changed after postmaster
* start, but the rest can change at SIGHUP.
*/
bool Redirect_stderr = false;
bool Logging_collector = false;
int Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
int Log_RotationSize = 10 * 1024;
char *Log_directory = NULL;
@ -87,7 +87,9 @@ extern bool redirection_done;
static pg_time_t next_rotation_time;
static bool pipe_eof_seen = false;
static FILE *syslogFile = NULL;
static FILE *csvlogFile = NULL;
static char *last_file_name = NULL;
static char *last_csvfile_name = NULL;
/*
* Buffers for saving partial messages from different backends. We don't expect
@ -132,12 +134,13 @@ 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);
static void open_csvlogfile(void);
#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 logfile_rotate(bool time_based_rotation, int size_rotation_for);
static char *logfile_getname(pg_time_t timestamp, char * suffix);
static void set_next_rotation_time(void);
static void sigHupHandler(SIGNAL_ARGS);
static void sigUsr1Handler(SIGNAL_ARGS);
@ -281,7 +284,7 @@ SysLoggerMain(int argc, char *argv[])
for (;;)
{
bool time_based_rotation = false;
int size_rotation_for = 0;
#ifndef WIN32
int bytesRead;
int rc;
@ -336,11 +339,20 @@ SysLoggerMain(int argc, char *argv[])
{
/* Do a rotation if file is too big */
if (ftell(syslogFile) >= Log_RotationSize * 1024L)
{
rotation_requested = true;
size_rotation_for |= LOG_DESTINATION_STDERR;
}
if (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L)
{
rotation_requested = true;
size_rotation_for |= LOG_DESTINATION_CSVLOG;
}
}
if (rotation_requested)
logfile_rotate(time_based_rotation);
logfile_rotate(time_based_rotation, size_rotation_for);
#ifndef WIN32
@ -405,7 +417,10 @@ SysLoggerMain(int argc, char *argv[])
if (pipe_eof_seen)
{
ereport(LOG,
/* seeing this message on the real stderr is annoying - so we
* make it DEBUG1 to suppress in normal use.
*/
ereport(DEBUG1,
(errmsg("logger shutting down")));
/*
@ -429,7 +444,7 @@ SysLogger_Start(void)
pid_t sysloggerPid;
char *filename;
if (!Redirect_stderr)
if (!Logging_collector)
return 0;
/*
@ -477,7 +492,7 @@ SysLogger_Start(void)
* The initial logfile is created right in the postmaster, to verify that
* the Log_directory is writable.
*/
filename = logfile_getname(time(NULL));
filename = logfile_getname(time(NULL), NULL);
syslogFile = fopen(filename, "a");
@ -688,6 +703,7 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
{
char *cursor = logbuffer;
int count = *bytes_in_logbuffer;
int dest = LOG_DESTINATION_STDERR;
/* While we have enough for a header, process data... */
while (count >= (int) sizeof(PipeProtoHeader))
@ -700,7 +716,8 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
p.pid != 0 &&
(p.is_last == 't' || p.is_last == 'f'))
(p.is_last == 't' || p.is_last == 'f' ||
p.is_last == 'T' || p.is_last == 'F' ))
{
chunklen = PIPE_HEADER_SIZE + p.len;
@ -708,7 +725,10 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
if (count < chunklen)
break;
if (p.is_last == 'f')
dest = (p.is_last == 'T' || p.is_last == 'F' ) ?
LOG_DESTINATION_CSVLOG : LOG_DESTINATION_STDERR;
if (p.is_last == 'f' || p.is_last == 'F')
{
/*
* Save a complete non-final chunk in the per-pid buffer
@ -751,7 +771,8 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
* 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);
write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
dest);
}
}
else
@ -778,14 +799,15 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
appendBinaryStringInfo(str,
cursor + PIPE_HEADER_SIZE,
p.len);
write_syslogger_file(str->data, str->len);
write_syslogger_file(str->data, str->len, dest);
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);
write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
dest);
}
}
@ -811,7 +833,8 @@ process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
if (cursor[chunklen] == '\0')
break;
}
write_syslogger_file(cursor, chunklen);
/* fall back on the stderr log as the destination */
write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
cursor += chunklen;
count -= chunklen;
}
@ -841,7 +864,7 @@ flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
if (saved_chunks[i].pid != 0)
{
str = &(saved_chunks[i].data);
write_syslogger_file(str->data, str->len);
write_syslogger_file(str->data, str->len, LOG_DESTINATION_STDERR);
saved_chunks[i].pid = 0;
pfree(str->data);
}
@ -851,7 +874,8 @@ flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
* remove any protocol headers that may exist in it.
*/
if (*bytes_in_logbuffer > 0)
write_syslogger_file(logbuffer, *bytes_in_logbuffer);
write_syslogger_file(logbuffer, *bytes_in_logbuffer,
LOG_DESTINATION_STDERR);
*bytes_in_logbuffer = 0;
}
@ -869,15 +893,21 @@ flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
* even though its stderr does not point at the syslog pipe.
*/
void
write_syslogger_file(const char *buffer, int count)
write_syslogger_file(const char *buffer, int count, int destination)
{
int rc;
FILE * logfile;
if (destination == LOG_DESTINATION_CSVLOG && csvlogFile == NULL)
open_csvlogfile();
logfile = destination == LOG_DESTINATION_CSVLOG ? csvlogFile : syslogFile ;
#ifndef WIN32
rc = fwrite(buffer, 1, count, syslogFile);
rc = fwrite(buffer, 1, count, logfile);
#else
EnterCriticalSection(&sysfileSection);
rc = fwrite(buffer, 1, count, syslogFile);
rc = fwrite(buffer, 1, count, logfile);
LeaveCriticalSection(&sysfileSection);
#endif
@ -938,13 +968,46 @@ pipeThread(void *arg)
}
#endif /* WIN32 */
/*
* open the csv log file - we do this opportunistically, because
* we don't know if CSV logging will be wanted.
*/
static void
open_csvlogfile(void)
{
char *filename;
FILE *fh;
filename = logfile_getname(time(NULL),".csv");
fh = fopen(filename, "a");
if (!fh)
ereport(FATAL,
(errcode_for_file_access(),
(errmsg("could not create log file \"%s\": %m",
filename))));
setvbuf(fh, NULL, LBF_MODE, 0);
#ifdef WIN32
_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
#endif
csvlogFile = fh;
pfree(filename);
}
/*
* perform logfile rotation
*/
static void
logfile_rotate(bool time_based_rotation)
logfile_rotate(bool time_based_rotation, int size_rotation_for)
{
char *filename;
char *csvfilename;
FILE *fh;
rotation_requested = false;
@ -955,9 +1018,17 @@ logfile_rotate(bool time_based_rotation)
* file name when we don't do the rotation immediately.
*/
if (time_based_rotation)
filename = logfile_getname(next_rotation_time);
{
filename = logfile_getname(next_rotation_time, NULL);
if (csvlogFile != NULL)
csvfilename = logfile_getname(next_rotation_time, ".csv");
}
else
filename = logfile_getname(time(NULL));
{
filename = logfile_getname(time(NULL), NULL);
if (csvlogFile != NULL)
csvfilename = logfile_getname(time(NULL), ".csv");
}
/*
* Decide whether to overwrite or append. We can overwrite if (a)
@ -970,61 +1041,132 @@ logfile_rotate(bool time_based_rotation)
* postmaster because it ain't gonna work in the EXEC_BACKEND case.) So we
* will always append in that situation, even though truncating would
* usually be safe.
*
* For consistency, we treat CSV logs the same even though they aren't
* opened in the postmaster.
*/
if (Log_truncate_on_rotation && time_based_rotation &&
last_file_name != NULL && strcmp(filename, last_file_name) != 0)
fh = fopen(filename, "w");
else
fh = fopen(filename, "a");
if (!fh)
if (time_based_rotation || (size_rotation_for & LOG_DESTINATION_STDERR))
{
int saveerrno = errno;
if (Log_truncate_on_rotation && time_based_rotation &&
last_file_name != NULL && strcmp(filename, last_file_name) != 0)
fh = fopen(filename, "w");
else
fh = fopen(filename, "a");
ereport(LOG,
(errcode_for_file_access(),
errmsg("could not open new log file \"%s\": %m",
filename)));
/*
* ENFILE/EMFILE are not too surprising on a busy system; just keep
* using the old file till we manage to get a new one. Otherwise,
* assume something's wrong with Log_directory and stop trying to
* create files.
*/
if (saveerrno != ENFILE && saveerrno != EMFILE)
if (!fh)
{
int saveerrno = errno;
ereport(LOG,
(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
Log_RotationAge = 0;
Log_RotationSize = 0;
(errcode_for_file_access(),
errmsg("could not open new log file \"%s\": %m",
filename)));
/*
* ENFILE/EMFILE are not too surprising on a busy system; just keep
* using the old file till we manage to get a new one. Otherwise,
* assume something's wrong with Log_directory and stop trying to
* create files.
*/
if (saveerrno != ENFILE && saveerrno != EMFILE)
{
ereport(LOG,
(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
Log_RotationAge = 0;
Log_RotationSize = 0;
}
pfree(filename);
return;
}
pfree(filename);
return;
setvbuf(fh, NULL, LBF_MODE, 0);
#ifdef WIN32
_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
#endif
/* On Windows, need to interlock against data-transfer thread */
#ifdef WIN32
EnterCriticalSection(&sysfileSection);
#endif
fclose(syslogFile);
syslogFile = fh;
#ifdef WIN32
LeaveCriticalSection(&sysfileSection);
#endif
/* instead of pfree'ing filename, remember it for next time */
if (last_file_name != NULL)
pfree(last_file_name);
last_file_name = filename;
}
setvbuf(fh, NULL, LBF_MODE, 0);
/* same as above, but for csv file. */
if (csvlogFile != NULL && (
time_based_rotation ||
(size_rotation_for & LOG_DESTINATION_STDERR)))
{
if (Log_truncate_on_rotation && time_based_rotation &&
last_csvfile_name != NULL &&
strcmp(csvfilename, last_csvfile_name) != 0)
fh = fopen(csvfilename, "w");
else
fh = fopen(csvfilename, "a");
if (!fh)
{
int saveerrno = errno;
ereport(LOG,
(errcode_for_file_access(),
errmsg("could not open new log file \"%s\": %m",
csvfilename)));
/*
* ENFILE/EMFILE are not too surprising on a busy system; just keep
* using the old file till we manage to get a new one. Otherwise,
* assume something's wrong with Log_directory and stop trying to
* create files.
*/
if (saveerrno != ENFILE && saveerrno != EMFILE)
{
ereport(LOG,
(errmsg("disabling automatic rotation (use SIGHUP to reenable)")));
Log_RotationAge = 0;
Log_RotationSize = 0;
}
pfree(csvfilename);
return;
}
setvbuf(fh, NULL, LBF_MODE, 0);
#ifdef WIN32
_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
_setmode(_fileno(fh), _O_TEXT); /* use CRLF line endings on Windows */
#endif
/* On Windows, need to interlock against data-transfer thread */
/* On Windows, need to interlock against data-transfer thread */
#ifdef WIN32
EnterCriticalSection(&sysfileSection);
EnterCriticalSection(&sysfileSection);
#endif
fclose(syslogFile);
syslogFile = fh;
fclose(csvlogFile);
syslogFile = fh;
#ifdef WIN32
LeaveCriticalSection(&sysfileSection);
LeaveCriticalSection(&sysfileSection);
#endif
/* instead of pfree'ing filename, remember it for next time */
if (last_csvfile_name != NULL)
pfree(last_csvfile_name);
last_csvfile_name = filename;
}
set_next_rotation_time();
/* instead of pfree'ing filename, remember it for next time */
if (last_file_name != NULL)
pfree(last_file_name);
last_file_name = filename;
}
@ -1034,7 +1176,7 @@ logfile_rotate(bool time_based_rotation)
* Result is palloc'd.
*/
static char *
logfile_getname(pg_time_t timestamp)
logfile_getname(pg_time_t timestamp, char * suffix)
{
char *filename;
int len;
@ -1058,6 +1200,14 @@ logfile_getname(pg_time_t timestamp)
Log_filename, (unsigned long) timestamp);
}
if (suffix != NULL)
{
len = strlen(filename);
if (len > 4 && (strcmp(filename+(len-4),".log") == 0))
len -= 4;
strncpy(filename + len, suffix, MAXPGPATH - len);
}
return filename;
}

6
src/backend/utils/adt/misc.c
View File

@ -8,7 +8,7 @@
*
*
* IDENTIFICATION
* $PostgreSQL: pgsql/src/backend/utils/adt/misc.c,v 1.56 2007/01/05 22:19:41 momjian Exp $
* $PostgreSQL: pgsql/src/backend/utils/adt/misc.c,v 1.57 2007/08/19 01:41:25 adunstan Exp $
*
*-------------------------------------------------------------------------
*/
@ -144,10 +144,10 @@ pg_rotate_logfile(PG_FUNCTION_ARGS)
(errcode(ERRCODE_INSUFFICIENT_PRIVILEGE),
(errmsg("must be superuser to rotate log files"))));
if (!Redirect_stderr)
if (!Logging_collector)
{
ereport(WARNING,
(errmsg("rotation not possible because log redirection not active")));
(errmsg("rotation not possible because log collection not active")));
PG_RETURN_BOOL(false);
}

308
src/backend/utils/error/elog.c
View File

@ -42,7 +42,7 @@
*
*
* IDENTIFICATION
* $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.193 2007/08/04 19:29:25 tgl Exp $
* $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.194 2007/08/19 01:41:25 adunstan Exp $
*
*-------------------------------------------------------------------------
*/
@ -104,6 +104,14 @@ static int errordata_stack_depth = -1; /* index of topmost active frame */
static int recursion_depth = 0; /* to detect actual recursion */
/* buffers for formatted timestamps that might be used by both
* log_line_prefix and csv logs.
*/
#define FORMATTED_TS_LEN 128
static char formatted_start_time[FORMATTED_TS_LEN];
static char formatted_log_time[FORMATTED_TS_LEN];
/* Macro for checking errordata_stack_depth is reasonable */
#define CHECK_STACK_DEPTH() \
@ -124,8 +132,8 @@ static const char *useful_strerror(int errnum);
static const char *error_severity(int elevel);
static void append_with_tabs(StringInfo buf, const char *str);
static bool is_log_level_output(int elevel, int log_min_level);
static void write_pipe_chunks(int fd, char *data, int len);
static void write_pipe_chunks(char *data, int len, int dest);
static void get_error_message(StringInfo buf, ErrorData *edata);
/*
* errstart --- begin an error-reporting cycle
@ -1434,12 +1442,14 @@ log_line_prefix(StringInfo buf)
/*
* 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.
* MyProcPid changes. MyStartTime also changes when MyProcPid does, so
* reset the formatted start timestamp too.
*/
if (log_my_pid != MyProcPid)
{
log_line_number = 0;
log_my_pid = MyProcPid;
formatted_start_time[0] = '\0';
}
log_line_number++;
@ -1498,8 +1508,7 @@ log_line_prefix(StringInfo buf)
struct timeval tv;
pg_time_t stamp_time;
pg_tz *tz;
char strfbuf[128],
msbuf[8];
char msbuf[8];
gettimeofday(&tv, NULL);
stamp_time = (pg_time_t) tv.tv_sec;
@ -1512,16 +1521,16 @@ log_line_prefix(StringInfo buf)
*/
tz = log_timezone ? log_timezone : gmt_timezone;
pg_strftime(strfbuf, sizeof(strfbuf),
pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
/* leave room for milliseconds... */
"%Y-%m-%d %H:%M:%S %Z",
pg_localtime(&stamp_time, tz));
/* 'paste' milliseconds into place... */
sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
strncpy(strfbuf + 19, msbuf, 4);
strncpy(formatted_log_time + 19, msbuf, 4);
appendStringInfoString(buf, strfbuf);
appendStringInfoString(buf, formatted_log_time);
}
break;
case 't':
@ -1539,18 +1548,18 @@ log_line_prefix(StringInfo buf)
}
break;
case 's':
if (formatted_start_time[0] == '\0')
{
pg_time_t stamp_time = (pg_time_t) MyStartTime;
pg_tz *tz;
char strfbuf[128];
tz = log_timezone ? log_timezone : gmt_timezone;
pg_strftime(strfbuf, sizeof(strfbuf),
pg_strftime(formatted_start_time, FORMATTED_TS_LEN,
"%Y-%m-%d %H:%M:%S %Z",
pg_localtime(&stamp_time, tz));
appendStringInfoString(buf, strfbuf);
}
appendStringInfoString(buf, formatted_start_time);
break;
case 'i':
if (MyProcPort)
@ -1596,6 +1605,245 @@ log_line_prefix(StringInfo buf)
}
}
/*
* append a CSV'd version of a string to a StringInfo
* We use the PostgreSQL defaults for CSV, i.e. quote = escape = '"'
*/
static inline void
appendCSVLiteral(StringInfo buf, const char* data)
{
const char * p = data;
char c;
appendStringInfoCharMacro(buf, '"');
while ( (c = *p++) != '\0' )
{
if (c == '"')
appendStringInfoCharMacro(buf, '"');
appendStringInfoCharMacro(buf, c);
}
appendStringInfoCharMacro(buf, '"');
}
/*
* Constructs the error message, depending on the Errordata it gets,
* in CSV (comma seperated values) format. The COPY command
* can then be used to load the messages into a table.
*/
static void
write_csvlog(ErrorData *edata)
{
StringInfoData msgbuf;
StringInfoData buf;
/* static counter for line numbers */
static long log_line_number = 0;
/* has counter been reset in current process? */
static int log_my_pid = 0;
/*
* This is one of the few places where we'd rather not inherit a static
* variable's value from the postmaster. But since we will, reset it when
* MyProcPid changes.
*/
if (log_my_pid != MyProcPid)
{
log_line_number = 0;
log_my_pid = MyProcPid;
formatted_start_time[0] = '\0';
}
log_line_number++;
initStringInfo(&msgbuf);
initStringInfo(&buf);
/*
* The format of the log output in CSV format:
* timestamp with milliseconds, username, databasename, session id,
* host and port number, process id, process line number, command tag,
* session start time, transaction id, error severity, sql state code,
* statement or error message.
*/
/* timestamp_with_milliseconds */
/*
* Check if the timestamp is already calculated for the syslog message,
* if it is, then no need to calculate it again, will use the same,
* else get the current timestamp. This is done to put same timestamp
* in both syslog and csvlog messages.
*/
if (formatted_log_time[0] == '\0')
{
struct timeval tv;
pg_time_t stamp_time;
pg_tz *tz;
char msbuf[8];
gettimeofday(&tv, NULL);
stamp_time = (pg_time_t) tv.tv_sec;
/*
* Normally we print log timestamps in log_timezone, but
* during startup we could get here before that's set.
* If so, fall back to gmt_timezone (which guc.c ensures
* is set up before Log_line_prefix can become nonempty).
*/
tz = log_timezone ? log_timezone : gmt_timezone;
pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
/* leave room for milliseconds... */
"%Y-%m-%d %H:%M:%S %Z",
pg_localtime(&stamp_time, tz));
/* 'paste' milliseconds into place... */
sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
strncpy(formatted_log_time + 19, msbuf, 4);
}
appendStringInfoString(&buf, formatted_log_time);
appendStringInfoChar(&buf, ',');
/* username */
if (MyProcPort)
{
const char *username = MyProcPort->user_name;
if (username == NULL || *username == '\0')
username = _("[unknown]");
appendCSVLiteral(&buf, username);
}
appendStringInfoChar(&buf, ',');
/* databasename */
if (MyProcPort)
{
const char *dbname = MyProcPort->database_name;
if (dbname == NULL || *dbname == '\0')
dbname = _("[unknown]");
appendCSVLiteral(&buf, dbname);
}
appendStringInfoChar(&buf, ',');
/* session id */
appendStringInfo(&buf, "%lx.%x",
(long) MyStartTime, MyProcPid);
appendStringInfoChar(&buf, ',');
/* Remote host and port */
if (MyProcPort && MyProcPort->remote_host)
{
appendStringInfo(&buf, "%s", MyProcPort->remote_host);
if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
appendStringInfo(&buf, ":%s", MyProcPort->remote_port);
}
appendStringInfoChar(&buf, ',');
/* Process id */
if (MyProcPid != 0)
appendStringInfo(&buf, "%d", MyProcPid);
appendStringInfoChar(&buf, ',');
/* Line number */
appendStringInfo(&buf, "%ld", log_line_number);
appendStringInfoChar(&buf, ',');
/* PS display */
if (MyProcPort)
{
const char *psdisp;
int displen;
psdisp = get_ps_display(&displen);
appendStringInfo(&msgbuf, "%.*s", displen, psdisp);
appendCSVLiteral(&buf, msgbuf.data);
resetStringInfo(&msgbuf);
}
appendStringInfoChar(&buf, ',');
/* session start timestamp */
if (formatted_start_time[0] == '\0')
{
pg_time_t stamp_time = (pg_time_t) MyStartTime;
pg_tz *tz;
tz = log_timezone ? log_timezone : gmt_timezone;
pg_strftime(formatted_start_time, FORMATTED_TS_LEN,
"%Y-%m-%d %H:%M:%S %Z",
pg_localtime(&stamp_time, tz));
}
appendStringInfoString(&buf, formatted_start_time);
appendStringInfoChar(&buf, ',');
/* Transaction id */
if (MyProcPort)
{
if (IsTransactionState())
appendStringInfo(&buf, "%u", GetTopTransactionId());
else
appendStringInfo(&buf, "%u", InvalidTransactionId);
}
appendStringInfoChar(&buf, ',');
/* Error severity */
if (error_severity(edata->elevel) != NULL)
appendStringInfo(&buf, "%s,", error_severity(edata->elevel));
else
appendStringInfoString(&buf, ",");
/* SQL state code */
if (Log_error_verbosity >= PGERROR_VERBOSE)
appendStringInfo(&buf, "%s",
unpack_sql_state(edata->sqlerrcode));
appendStringInfoChar(&buf, ',');
/* Error message and cursor position if any */
get_error_message(&msgbuf, edata);
appendCSVLiteral(&buf, msgbuf.data);
appendStringInfoChar(&buf, '\n');
/* If in the syslogger process, try to write messages direct to file */
if (am_syslogger)
write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
else
write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_CSVLOG);
pfree(msgbuf.data);
pfree(buf.data);
}
/*
* Appends the buffer with the error message and the cursor position.
*/
static void
get_error_message(StringInfo buf, ErrorData *edata)
{
if (edata->message)
appendStringInfo(buf, "%s", edata->message);
else
appendStringInfo(buf, "%s", _("missing error text"));
if (edata->cursorpos > 0)
appendStringInfo(buf, _(" at character %d"),
edata->cursorpos);
else if (edata->internalpos > 0)
appendStringInfo(buf, _(" at character %d"),
edata->internalpos);
}
/*
* Unpack MAKE_SQLSTATE code. Note that this returns a pointer to a
* static buffer.
@ -1627,6 +1875,8 @@ send_message_to_server_log(ErrorData *edata)
initStringInfo(&buf);
formatted_log_time[0] = '\0';
log_line_prefix(&buf);
appendStringInfo(&buf, "%s: ", error_severity(edata->elevel));
@ -1766,7 +2016,7 @@ send_message_to_server_log(ErrorData *edata)
* syslogger. Otherwise, just do a vanilla write to stderr.
*/
if (redirection_done && !am_syslogger)
write_pipe_chunks(fileno(stderr), buf.data, buf.len);
write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_STDERR);
#ifdef WIN32
/*
* In a win32 service environment, there is no usable stderr. Capture
@ -1782,9 +2032,31 @@ send_message_to_server_log(ErrorData *edata)
write(fileno(stderr), buf.data, buf.len);
}
if (Log_destination & LOG_DESTINATION_CSVLOG)
{
if (redirection_done || am_syslogger)
{
/* send CSV data if it's safe to do so (syslogger doesn't need
* the pipe)
*/
write_csvlog(edata);
}
else
{
char * msg = _("Not safe to send CSV data\n");
write(fileno(stderr),msg,strlen(msg));
if ( ! (Log_destination & LOG_DESTINATION_STDERR) &&
whereToSendOutput != DestDebug)
{
/* write message to stderr unless we just sent it above */
write(fileno(stderr), buf.data, buf.len);
}
}
}
/* If in the syslogger process, try to write messages direct to file */
if (am_syslogger)
write_syslogger_file(buf.data, buf.len);
write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_STDERR);
pfree(buf.data);
}
@ -1793,10 +2065,12 @@ send_message_to_server_log(ErrorData *edata)
* Send data to the syslogger using the chunked protocol
*/
static void
write_pipe_chunks(int fd, char *data, int len)
write_pipe_chunks(char *data, int len, int dest)
{
PipeProtoChunk p;
int fd = fileno(stderr);
Assert(len > 0);
p.proto.nuls[0] = p.proto.nuls[1] = '\0';
@ -1805,7 +2079,7 @@ write_pipe_chunks(int fd, char *data, int len)
/* write all but the last chunk */
while (len > PIPE_MAX_PAYLOAD)
{
p.proto.is_last = 'f';
p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'F' : 'f');
p.proto.len = PIPE_MAX_PAYLOAD;
memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD);
write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD);
@ -1814,7 +2088,7 @@ write_pipe_chunks(int fd, char *data, int len)
}
/* write the last chunk */
p.proto.is_last = 't';
p.proto.is_last = (dest == LOG_DESTINATION_CSVLOG ? 'T' : 't');
p.proto.len = len;
memcpy(p.proto.data, data, len);
write(fd, &p, PIPE_HEADER_SIZE + len);

12
src/backend/utils/misc/guc.c
View File

@ -10,7 +10,7 @@
* Written by Peter Eisentraut <peter_e@gmx.net>.
*
* IDENTIFICATION
* $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.412 2007/08/13 19:27:11 tgl Exp $
* $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.413 2007/08/19 01:41:25 adunstan Exp $
*
*--------------------------------------------------------------------
*/
@ -968,11 +968,11 @@ static struct config_bool ConfigureNamesBool[] =
false, NULL, NULL
},
{
{"redirect_stderr", PGC_POSTMASTER, LOGGING_WHERE,
gettext_noop("Start a subprocess to capture stderr output into log files."),
{"logging_collector", PGC_POSTMASTER, LOGGING_WHERE,
gettext_noop("Start a subprocess to capture stderr output and/or csvlogs into log files."),
NULL
},
&Redirect_stderr,
&Logging_collector,
false, NULL, NULL
},
{
@ -2241,7 +2241,7 @@ static struct config_string ConfigureNamesString[] =
{"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."),
" \"csvlog\" and \"eventlog\", depending on the platform."),
GUC_LIST_INPUT
},
&log_destination_string,
@ -6313,6 +6313,8 @@ assign_log_destination(const char *value, bool doit, GucSource source)
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;

9
src/backend/utils/misc/postgresql.conf.sample
View File

@ -229,15 +229,16 @@
# - Where to Log -
#log_destination = 'stderr' # Valid values are combinations of
# stderr, syslog and eventlog,
# stderr, csvlog, syslog and eventlog,
# depending on platform.
# csvlog requires logging_collector to be on
# This is used when logging to stderr:
#redirect_stderr = off # Enable capturing of stderr into log
# files
#logging_collector = off # Enable capturing of stderr and csvlog
# into log files. Required to be on for csvlogs.
# (change requires restart)
# These are only used if redirect_stderr is on:
# These are only used if logging_collector 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.

16
src/include/postmaster/syslogger.h
View File

@ -5,7 +5,7 @@
*
* Copyright (c) 2004-2007, PostgreSQL Global Development Group
*
* $PostgreSQL: pgsql/src/include/postmaster/syslogger.h,v 1.10 2007/07/25 12:22:53 mha Exp $
* $PostgreSQL: pgsql/src/include/postmaster/syslogger.h,v 1.11 2007/08/19 01:41:25 adunstan Exp $
*
*-------------------------------------------------------------------------
*/
@ -24,9 +24,9 @@
* also cope with non-protocol data coming down the pipe, though we cannot
* guarantee long strings won't get split apart.
*
* We use 't' or 'f' instead of a bool for is_last to make the protocol a tiny
* bit more robust against finding a false double nul byte prologue. But we
* still might find it in the len and/or pid bytes unless we're careful.
* We use non-nul bytes in is_last to make the protocol a tiny bit
* more robust against finding a false double nul byte prologue. But
* we still might find it in the len and/or pid bytes unless we're careful.
*/
#ifdef PIPE_BUF
@ -46,7 +46,9 @@ typedef struct
char nuls[2]; /* always \0\0 */
uint16 len; /* size of this chunk (counts data only) */
int32 pid; /* writer's pid */
char is_last; /* last chunk of message? 't' or 'f' */
char is_last; /* last chunk of message? 't' or 'f'
* ('T' or 'F' for CSV case)
*/
char data[1]; /* data payload starts here */
} PipeProtoHeader;
@ -61,7 +63,7 @@ typedef union
/* GUC options */
extern bool Redirect_stderr;
extern bool Logging_collector;
extern int Log_RotationAge;
extern int Log_RotationSize;
extern PGDLLIMPORT char *Log_directory;
@ -79,7 +81,7 @@ extern HANDLE syslogPipe[2];
extern int SysLogger_Start(void);
extern void write_syslogger_file(const char *buffer, int count);
extern void write_syslogger_file(const char *buffer, int count, int dest);
#ifdef EXEC_BACKEND
extern void SysLoggerMain(int argc, char *argv[]);

3
src/include/utils/elog.h
View File

@ -7,7 +7,7 @@
* Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
* Portions Copyright (c) 1994, Regents of the University of California
*
* $PostgreSQL: pgsql/src/include/utils/elog.h,v 1.87 2007/07/25 12:22:54 mha Exp $
* $PostgreSQL: pgsql/src/include/utils/elog.h,v 1.88 2007/08/19 01:41:25 adunstan Exp $
*
*-------------------------------------------------------------------------
*/
@ -291,6 +291,7 @@ extern int Log_destination;
#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);

4
src/test/bench/runwisc.sh
View File

@ -1,5 +1,5 @@
#!/bin/sh
# $PostgreSQL: pgsql/src/test/bench/runwisc.sh,v 1.9 2007/08/01 22:24:32 momjian Exp $
# $PostgreSQL: pgsql/src/test/bench/runwisc.sh,v 1.10 2007/08/19 01:41:25 adunstan Exp $
if [ ! -d $1 ]; then
echo " you must specify a valid data directory " >&2
@ -14,4 +14,4 @@ echo =============== vacuuming benchmark database... ================= >&2
echo "vacuum" | postgres -D"$1" bench > /dev/null
echo =============== running benchmark... ================= >&2
time postgres -D"$1" -texecutor -tplanner -c log_min_messages=log -c log_destination=stderr -c redirect_stderr=off bench < bench.sql 2>&1
time postgres -D"$1" -texecutor -tplanner -c log_min_messages=log -c log_destination=stderr -c start_log_collector=off bench < bench.sql 2>&1