postgres源码解析 SysLogger辅助进程
简介
SysLogger是一个信息收集进程，它通过管道从postmaster、后台进程和所有的子进程收集所有的stderr输出，并将这些输出写入到文件中，这些信息在数据库出现故障时能够起到非常重要的作用。
工作流程梳理
1 管道创建
/*
* Postmaster subroutine to start a syslogger subprocess.
*/
int
SysLogger_Start(void)
{
pid_t sysloggerPid;
char *filename;
if (!Logging_collector)
return 0;
/*
* If first time through, create the pipe which will receive stderr
* output.
// 启动第一次会创建一个管道用于接受错误输出
* If the syslogger crashes and needs to be restarted, we continue to use
* the same pipe (indeed must do so, since extant backends will be writing
* into that pipe).
// 当syslogger进程奔溃后重启时，会用同一个管道
* This means the postmaster must continue to hold the read end of the
* pipe open, so we can pass it down to the reincarnated syslogger. This
* is a bit klugy but we have little choice.
// postmaster 必须继续保持管道的读取端打开，以便我们可以将其传递给转世的 syslogger。
* Also note that we don't bother counting the pipe FDs by calling
* Reserve/ReleaseExternalFD. There's no real need to account for them
* accurately in the postmaster or syslogger process, and both ends of the
* pipe will wind up closed in all other postmaster children.
* 另请注意，我们不会通过调用 Reserve/ReleaseExternalFD 来计算管道 FD。
* 在 postmaster 或 syslogger 进程中没有真正需要准确地考虑它们，并且管道的两端将在
* 所有其他 postmaster 子进程中关闭。
*/
#ifndef WIN32
if (syslogPipe[0] < 0)
{
if (pipe(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
*/
(void) MakePGDirectory(Log_directory);
2 创建或打开日志文件，fork syslogger子进程
/*
* The initial logfile is created right in the postmaster, to verify that
* the Log_directory is writable. We save the reference time so that the
* syslogger child process can recompute this file name.
// 起始的日志文件有postmaster创建，验证日志文件的可写性。我们保存引用次数以使syslogge子进程
* 重计算文件名
*
* It might look a bit strange to re-do this during a syslogger restart,
* but we must do so since the postmaster closed syslogFile after the
* previous fork (and remembering that old file wouldn't be right anyway).
* Note we always append here, we won't overwrite any existing file. This
* is consistent with the normal rules, because by definition this is not
* a time-based rotation.
* 在syslogger重启时会重新执行该操作，虽显得有点奇怪。但是我们必须这么做是因为 postmaster会
* 在之前fork子进程后关闭syslogFile。
* 总是追加内容，不会重写有存在的文件。与普通的规则类型，不是基于时间的轮换
*/
first_syslogger_file_time = time(NULL);
filename = logfile_getname(first_syslogger_file_time, NULL); // 获取文件名
syslogFile = logfile_open(filename, "a", false); // 打开上述指定文件
pfree(filename);
/*
* Likewise for the initial CSV log file, if that's enabled. (Note that
* we open syslogFile even when only CSV output is nominally enabled,
* since some code paths will write to syslogFile anyway.)
*/
if (Log_destination & LOG_DESTINATION_CSVLOG) // 若开启 CSV输出模式，创建/打开相应文件
{
filename = logfile_getname(first_syslogger_file_time, ".csv");
csvlogFile = logfile_open(filename, "a", false);
pfree(filename);
}
#ifdef EXEC_BACKEND
switch ((sysloggerPid = syslogger_forkexec())) // fork 子进程 syslogger
#else
switch ((sysloggerPid = fork_process()))
#endif
{
case -1:
ereport(LOG,
(errmsg("could not fork system logger: %m")));
return 0;
#ifndef EXEC_BACKEND
case 0:
/* in postmaster child ... */
InitPostmasterChild(); // 初始化子进程的运行环境：初始化进程私有latch、信号处理函数
/* Close the postmaster's sockets */
ClosePostmasterPorts(true); // 关闭postmaster的监听描述符
/* Drop our connection to postmaster's shared memory, as well */
dsm_detach_all();
PGSharedMemoryDetach(); // 丢弃与postmaster共享内存间的联系
/* do the work */
SysLoggerMain(0, NULL); //调用 SysLoggerMain函数执行日志信息收集
break;
#endif
default:
/* success, in postmaster */
SysLoggerMain执行流程：
准备工作
1：初始化全局变量，获取当前时间，设置进程标识；
2： 如果重启需要对stderr和管道重新设置；
3：注册信号处理函数，包括SIGHUP信号重新读取配置文件、SIGUSR1日志切换请求；
4：记录当前日志文件名+日志所在目录，设置写一次切换日志文件时期；
/*
* Main entry point for syslogger process
* argc/argv parameters are valid only in EXEC_BACKEND case.
*/
NON_EXEC_STATIC void
SysLoggerMain(int argc, char *argv[])
{
#ifndef WIN32
char logbuffer[READ_BUF_SIZE];
int bytes_in_logbuffer = 0;
#endif
char *currentLogDir;
char *currentLogFilename;
int currentLogRotationAge;
pg_time_t now;
WaitEventSet *wes;
now = MyStartTime;
#ifdef EXEC_BACKEND
syslogger_parseArgs(argc, argv);
#endif /* EXEC_BACKEND */
MyBackendType = B_LOGGER;
init_ps_display(NULL);
/*
* If we restarted, our stderr is already redirected into our own input
* pipe. This is of course pretty useless, not to mention that it
* interferes with detecting pipe EOF. Point stderr to /dev/null. This
* 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(DEVNULL, O_WRONLY, 0);
/*
* The closes might look redundant, but they are not: we want to be
* darn sure the pipe gets closed even if the open failed. We can
* survive running with stderr pointing nowhere, but we can't afford
* to have extra pipe input descriptors hanging around.
*
* As we're just trying to reset these to go to DEVNULL, there's not
* much point in checking for failure from the close/dup2 calls here,
* if they fail then presumably the file descriptors are closed and
* any writes will go into the bitbucket anyway.
*/
close(fileno(stdout));
close(fileno(stderr));
if (fd != -1)
{
(void) dup2(fd, fileno(stdout)); // 将stdout和stderr 重定向至日志管道的写入端
(void) dup2(fd, fileno(stderr));
close(fd);
}
}
/*
* Syslogger's own stderr can't be the syslogPipe, so set it back to text
* mode if we didn't just close it. (It was set to binary in
* SubPostmasterMain).
*/
#ifdef WIN32
else
_setmode(_fileno(stderr), _O_TEXT);
#endif
/*
* Also close our copy of the write end of the pipe. This is needed to
* ensure we can detect pipe EOF correctly. (But note that in the restart
* case, the postmaster already did this.)
*/
#ifndef WIN32
if (syslogPipe[1] >= 0) // 关闭管道的写段，确保能正确检测管道EOF
close(syslogPipe[1]);
syslogPipe[1] = -1;
#else
if (syslogPipe[1])
CloseHandle(syslogPipe[1]);
syslogPipe[1] = 0;
#endif
/*
* Properly accept or ignore signals the postmaster might send us
*
* Note: we ignore all termination signals, and instead exit only when all
* upstream processes are gone, to ensure we don't miss any dying gasps of
* broken backends...
*/
pqsignal(SIGHUP, SignalHandlerForConfigReload); /* set flag to read config
* file */
pqsignal(SIGINT, SIG_IGN);
pqsignal(SIGTERM, SIG_IGN);
pqsignal(SIGQUIT, SIG_IGN);
pqsignal(SIGALRM, SIG_IGN);
pqsignal(SIGPIPE, SIG_IGN);
pqsignal(SIGUSR1, sigUsr1Handler); /* request log rotation */
pqsignal(SIGUSR2, SIG_IGN);
/*
* Reset some signals that are accepted by postmaster but not here
*/
pqsignal(SIGCHLD, SIG_DFL);
PG_SETMASK(&UnBlockSig);
#ifdef WIN32
/* Fire up separate data transfer thread */
InitializeCriticalSection(&sysloggerSection);
EnterCriticalSection(&sysloggerSection);
threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
if (threadHandle == 0)
elog(FATAL, "could not create syslogger data transfer thread: %m");
#endif /* WIN32 */
/*
* Remember active logfiles' name(s). We recompute 'em from the reference
* time because passing down just the pg_time_t is a lot cheaper than
* passing a whole file path in the EXEC_BACKEND case.
*/
last_file_name = logfile_getname(first_syslogger_file_time, NULL);
if (csvlogFile != NULL)
last_csv_file_name = logfile_getname(first_syslogger_file_time, ".csv");
/* remember active logfile parameters */
currentLogDir = pstrdup(Log_directory);
currentLogFilename = pstrdup(Log_filename);
currentLogRotationAge = Log_RotationAge;
/* set next planned rotation time */
set_next_rotation_time();
update_metainfo_datafile();
/*
* Reset whereToSendOutput, as the postmaster will do (but hasn't yet, at
* the point where we forked). This prevents duplicate output of messages
* from syslogger itself.
*/
whereToSendOutput = DestNone;
/*
* Set up a reusable WaitEventSet object we'll use to wait for our latch,
* and (except on Windows) our socket.
// 设置可重用的 WaitEventSet 对象，该对象在等待 latch时使用
* Unlike all other postmaster child processes, we'll ignore postmaster
* death because we want to collect final log output from all backends and
* then exit last. We'll do that by running until we see EOF on the
* syslog pipe, which implies that all other backends have exited
* (including the postmaster).
*
* 与其他 postmaster子进程不一样的是，syslogger子进程忽略postmaster的crash，其原因是
* 该进程收集的是所有后端进程的最终日志输出，直至看到 管道的EOF标识后退出
*/
wes = CreateWaitEventSet(CurrentMemoryContext, 2);
AddWaitEventToSet(wes, WL_LATCH_SET, PGINVALID_SOCKET, MyLatch, NULL);
#ifndef WIN32
AddWaitEventToSet(wes, WL_SOCKET_READABLE, syslogPipe[0], NULL, NULL);
#endif
日志收集工作
5 ：重设Latch,处理最近收到的任何请求或者信号；
6：根据配置文件判断Log_directory 、 Log_filename是否与当前文件信息相同，不同则需要根据配置文件的相关
信息创建、打开；
7：判断Log_RotationAge参数是否发生变化，是则作出相应的调整；
8：判断是否达到文件切换周期、是否达到规定的日志文件大小，满足则调用logfile_rotate函数创建新的日志文件；
9：睡眠直至有事件的到来，如果有调用read系统函数从管道的读端获取数据存放在临时缓存logbuffer中, 每读取
一次会调用process_pipe_input将读取的数据进行处理；
10： 不断的重复上述8直到读取管道的EOF标识[意味着数据读取完毕，所有的后台进程正常退出]，调用
flush_pipe_input将logbuffer写入日志文件；
11： 上述步骤完成后，syslogger进程退出。
/* main worker loop */
for (;;)
{
bool time_based_rotation = false;
int size_rotation_for = 0;
long cur_timeout;
WaitEvent event;
#ifndef WIN32
int rc;
#endif
/* Clear any already-pending wakeups */
ResetLatch(MyLatch);
/*
* Process any requests or signals received recently.
*/
if (ConfigReloadPending)
{
ConfigReloadPending = false;
ProcessConfigFile(PGC_SIGHUP);
/*
* Check if the log directory or filename pattern changed in
* postgresql.conf. If so, force rotation to make sure we're
* writing the logfiles in the right place.
*/
if (strcmp(Log_directory, currentLogDir) != 0)
{
pfree(currentLogDir);
currentLogDir = pstrdup(Log_directory);
rotation_requested = true;
/*
* Also, create new directory if not present; ignore errors
*/
(void) MakePGDirectory(Log_directory);
}
if (strcmp(Log_filename, currentLogFilename) != 0)
{
pfree(currentLogFilename);
currentLogFilename = pstrdup(Log_filename);
rotation_requested = true;
}
/*
* Force a rotation if CSVLOG output was just turned on or off and
* we need to open or close csvlogFile accordingly.
*/
if (((Log_destination & LOG_DESTINATION_CSVLOG) != 0) !=
(csvlogFile != NULL))
rotation_requested = true;
/*
* If rotation time parameter changed, reset next rotation time,
* but don't immediately force a rotation.
*/
if (currentLogRotationAge != Log_RotationAge)
{
currentLogRotationAge = Log_RotationAge;
set_next_rotation_time();
}
/*
* If we had a rotation-disabling failure, re-enable rotation
* attempts after SIGHUP, and force one immediately.
*/
if (rotation_disabled)
{
rotation_disabled = false;
rotation_requested = true;
}
/*
* Force rewriting last log filename when reloading configuration.
* Even if rotation_requested is false, log_destination may have
* been changed and we don't want to wait the next file rotation.
*/
update_metainfo_datafile();
}
if (Log_RotationAge > 0 && !rotation_disabled)
{
/* Do a logfile rotation if it's time */
now = (pg_time_t) time(NULL);
if (now >= next_rotation_time)
rotation_requested = time_based_rotation = true;
}
if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
{
/* 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)
{
/*
* Force rotation when both values are zero. It means the request
* was sent by pg_rotate_logfile() or "pg_ctl logrotate".
*/
if (!time_based_rotation && size_rotation_for == 0)
size_rotation_for = LOG_DESTINATION_STDERR | LOG_DESTINATION_CSVLOG;
logfile_rotate(time_based_rotation, size_rotation_for);
}
/*
* Calculate time till next time-based rotation, so that we don't
* sleep longer than that. We assume the value of "now" obtained
* above is still close enough. Note we can't make this calculation
* until after calling logfile_rotate(), since it will advance
* next_rotation_time.
*
* Also note that we need to beware of overflow in calculation of the
* timeout: with large settings of Log_RotationAge, next_rotation_time
* could be more than INT_MAX msec in the future. In that case we'll
* wait no more than INT_MAX msec, and try again.
*/
if (Log_RotationAge > 0 && !rotation_disabled)
{
pg_time_t delay;
delay = next_rotation_time - now;
if (delay > 0)
{
if (delay > INT_MAX / 1000)
delay = INT_MAX / 1000;
cur_timeout = delay * 1000L; /* msec */
}
else
cur_timeout = 0;
}
else
cur_timeout = -1L;
/*
* Sleep until there's something to do
*/
#ifndef WIN32
rc = WaitEventSetWait(wes, cur_timeout, &event, 1,
WAIT_EVENT_SYSLOGGER_MAIN);
if (rc == 1 && event.events == WL_SOCKET_READABLE)
{
int bytesRead;
bytesRead = read(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 */
/*
* On Windows we leave it to a separate thread to transfer data and
* detect pipe EOF. The main thread just wakes up to handle SIGHUP
* and rotation conditions.
*
* Server code isn't generally thread-safe, so we ensure that only one
* of the threads is active at a time by entering the critical section
* whenever we're not sleeping.
*/
LeaveCriticalSection(&sysloggerSection);
(void) WaitEventSetWait(wes, cur_timeout, &event, 1,
WAIT_EVENT_SYSLOGGER_MAIN);
EnterCriticalSection(&sysloggerSection);
#endif /* WIN32 */
if (pipe_eof_seen) // 结束标志
{
/*
* seeing this message on the real stderr is annoying - so we make
* it DEBUG1 to suppress in normal use.
*/
ereport(DEBUG1,
(errmsg_internal("logger shutting down")));
/*
* Normal exit from the syslogger is here. Note that we
* deliberately do not close syslogFile before exiting; this is to
* allow for the possibility of elog messages being generated
* inside proc_exit. Regular exit() will take care of flushing
* and closing stdio channels.
* 进程退出，
*/
proc_exit(0);
}
}
}
配置文件相关参数
# - Where to Log -
log_destination = 'csvlog' # Valid values are combinations of
# stderr, csvlog, syslog, and eventlog,
# depending on platform. csvlog
# requires logging_collector to be on.
# This is used when logging to stderr:
logging_collector = on # Enable capturing of stderr and csvlog
# into log files. Required to be on for
# csvlogs.
# (change requires restart)
# These are only used if logging_collector is on:
#log_directory = '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,
# can include strftime() escapes
#log_file_mode = 0600 # creation mode for log files,
# begin with 0 to use octal notation
#log_rotation_age = 1d # Automatic rotation of logfiles will
#log_rotation_size = 10MB # Automatic rotation of logfiles will
# happen after that much log output.
# 0 disables.
#log_truncate_on_rotation = off # If on, an existing log file with the
# same name as the new log file will be
# truncated rather than appended to.
# But such truncation only occurs on
# time-driven rotation, not on restarts
# or size-driven rotation. Default is
# off, meaning append to existing files
# in all cases.
参考： http://postgres.cn/docs/13/runtime-config-logging.html