Branch data Line data Source code
1 : : /*-------------------------------------------------------------------------
2 : : *
3 : : * syslogger.c
4 : : *
5 : : * The system logger (syslogger) appeared in Postgres 8.0. It catches all
6 : : * stderr output from the postmaster, backends, and other subprocesses
7 : : * by redirecting to a pipe, and writes it to a set of logfiles.
8 : : * It's possible to have size and age limits for the logfile configured
9 : : * in postgresql.conf. If these limits are reached or passed, the
10 : : * current logfile is closed and a new one is created (rotated).
11 : : * The logfiles are stored in a subdirectory (configurable in
12 : : * postgresql.conf), using a user-selectable naming scheme.
13 : : *
14 : : * Author: Andreas Pflug <pgadmin@pse-consulting.de>
15 : : *
16 : : * Copyright (c) 2004-2026, PostgreSQL Global Development Group
17 : : *
18 : : *
19 : : * IDENTIFICATION
20 : : * src/backend/postmaster/syslogger.c
21 : : *
22 : : *-------------------------------------------------------------------------
23 : : */
24 : : #include "postgres.h"
25 : :
26 : : #include <fcntl.h>
27 : : #include <limits.h>
28 : : #include <signal.h>
29 : : #include <time.h>
30 : : #include <unistd.h>
31 : : #include <sys/stat.h>
32 : : #include <sys/time.h>
33 : :
34 : : #include "common/file_perm.h"
35 : : #include "lib/stringinfo.h"
36 : : #include "libpq/pqsignal.h"
37 : : #include "miscadmin.h"
38 : : #include "nodes/pg_list.h"
39 : : #include "pgstat.h"
40 : : #include "pgtime.h"
41 : : #include "port/pg_bitutils.h"
42 : : #include "postmaster/interrupt.h"
43 : : #include "postmaster/postmaster.h"
44 : : #include "postmaster/syslogger.h"
45 : : #include "storage/dsm.h"
46 : : #include "storage/fd.h"
47 : : #include "storage/ipc.h"
48 : : #include "storage/latch.h"
49 : : #include "storage/pg_shmem.h"
50 : : #include "tcop/tcopprot.h"
51 : : #include "utils/guc.h"
52 : : #include "utils/memutils.h"
53 : : #include "utils/ps_status.h"
54 : :
55 : : /*
56 : : * We read() into a temp buffer twice as big as a chunk, so that any fragment
57 : : * left after processing can be moved down to the front and we'll still have
58 : : * room to read a full chunk.
59 : : */
60 : : #define READ_BUF_SIZE (2 * PIPE_CHUNK_SIZE)
61 : :
62 : : /* Log rotation signal file path, relative to $PGDATA */
63 : : #define LOGROTATE_SIGNAL_FILE "logrotate"
64 : :
65 : :
66 : : /*
67 : : * GUC parameters. Logging_collector cannot be changed after postmaster
68 : : * start, but the rest can change at SIGHUP.
69 : : */
70 : : bool Logging_collector = false;
71 : : int Log_RotationAge = HOURS_PER_DAY * MINS_PER_HOUR;
72 : : int Log_RotationSize = 10 * 1024;
73 : : char *Log_directory = NULL;
74 : : char *Log_filename = NULL;
75 : : bool Log_truncate_on_rotation = false;
76 : : int Log_file_mode = S_IRUSR | S_IWUSR;
77 : :
78 : : /*
79 : : * Private state
80 : : */
81 : : static pg_time_t next_rotation_time;
82 : : static bool pipe_eof_seen = false;
83 : : static bool rotation_disabled = false;
84 : : static FILE *syslogFile = NULL;
85 : : static FILE *csvlogFile = NULL;
86 : : static FILE *jsonlogFile = NULL;
87 : : NON_EXEC_STATIC pg_time_t first_syslogger_file_time = 0;
88 : : static char *last_sys_file_name = NULL;
89 : : static char *last_csv_file_name = NULL;
90 : : static char *last_json_file_name = NULL;
91 : :
92 : : /*
93 : : * Buffers for saving partial messages from different backends.
94 : : *
95 : : * Keep NBUFFER_LISTS lists of these, with the entry for a given source pid
96 : : * being in the list numbered (pid % NBUFFER_LISTS), so as to cut down on
97 : : * the number of entries we have to examine for any one incoming message.
98 : : * There must never be more than one entry for the same source pid.
99 : : *
100 : : * An inactive buffer is not removed from its list, just held for re-use.
101 : : * An inactive buffer has pid == 0 and undefined contents of data.
102 : : */
103 : : typedef struct
104 : : {
105 : : int32 pid; /* PID of source process */
106 : : StringInfoData data; /* accumulated data, as a StringInfo */
107 : : } save_buffer;
108 : :
109 : : #define NBUFFER_LISTS 256
110 : : static List *buffer_lists[NBUFFER_LISTS];
111 : :
112 : : /* These must be exported for EXEC_BACKEND case ... annoying */
113 : : #ifndef WIN32
114 : : int syslogPipe[2] = {-1, -1};
115 : : #else
116 : : HANDLE syslogPipe[2] = {0, 0};
117 : : #endif
118 : :
119 : : #ifdef WIN32
120 : : static HANDLE threadHandle = 0;
121 : : static CRITICAL_SECTION sysloggerSection;
122 : : #endif
123 : :
124 : : /*
125 : : * Flags set by interrupt handlers for later service in the main loop.
126 : : */
127 : : static volatile sig_atomic_t rotation_requested = false;
128 : :
129 : :
130 : : /* Local subroutines */
131 : : #ifdef EXEC_BACKEND
132 : : static int syslogger_fdget(FILE *file);
133 : : static FILE *syslogger_fdopen(int fd);
134 : : #endif
135 : : static void process_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
136 : : static void flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer);
137 : : static FILE *logfile_open(const char *filename, const char *mode,
138 : : bool allow_errors);
139 : :
140 : : #ifdef WIN32
141 : : static unsigned int __stdcall pipeThread(void *arg);
142 : : #endif
143 : : static void logfile_rotate(bool time_based_rotation, int size_rotation_for);
144 : : static bool logfile_rotate_dest(bool time_based_rotation,
145 : : int size_rotation_for, pg_time_t fntime,
146 : : int target_dest, char **last_file_name,
147 : : FILE **logFile);
148 : : static char *logfile_getname(pg_time_t timestamp, const char *suffix);
149 : : static void set_next_rotation_time(void);
150 : : static void sigUsr1Handler(SIGNAL_ARGS);
151 : : static void update_metainfo_datafile(void);
152 : :
153 : : typedef struct
154 : : {
155 : : int syslogFile;
156 : : int csvlogFile;
157 : : int jsonlogFile;
158 : : } SysloggerStartupData;
159 : :
160 : : /*
161 : : * Main entry point for syslogger process
162 : : * argc/argv parameters are valid only in EXEC_BACKEND case.
163 : : */
164 : : void
165 : 0 : SysLoggerMain(const void *startup_data, size_t startup_data_len)
166 : : {
167 : : #ifndef WIN32
168 : 0 : char logbuffer[READ_BUF_SIZE];
169 : 0 : int bytes_in_logbuffer = 0;
170 : : #endif
171 : 0 : char *currentLogDir;
172 : 0 : char *currentLogFilename;
173 : 0 : int currentLogRotationAge;
174 : 0 : pg_time_t now;
175 : 0 : WaitEventSet *wes;
176 : :
177 : : /*
178 : : * Re-open the error output files that were opened by SysLogger_Start().
179 : : *
180 : : * We expect this will always succeed, which is too optimistic, but if it
181 : : * fails there's not a lot we can do to report the problem anyway. As
182 : : * coded, we'll just crash on a null pointer dereference after failure...
183 : : */
184 : : #ifdef EXEC_BACKEND
185 : : {
186 : : const SysloggerStartupData *slsdata = startup_data;
187 : :
188 : : Assert(startup_data_len == sizeof(*slsdata));
189 : : syslogFile = syslogger_fdopen(slsdata->syslogFile);
190 : : csvlogFile = syslogger_fdopen(slsdata->csvlogFile);
191 : : jsonlogFile = syslogger_fdopen(slsdata->jsonlogFile);
192 : : }
193 : : #else
194 [ # # ]: 0 : Assert(startup_data_len == 0);
195 : : #endif
196 : :
197 : : /*
198 : : * Now that we're done reading the startup data, release postmaster's
199 : : * working memory context.
200 : : */
201 [ # # ]: 0 : if (PostmasterContext)
202 : : {
203 : 0 : MemoryContextDelete(PostmasterContext);
204 : 0 : PostmasterContext = NULL;
205 : 0 : }
206 : :
207 : 0 : now = MyStartTime;
208 : :
209 : 0 : MyBackendType = B_LOGGER;
210 : 0 : init_ps_display(NULL);
211 : :
212 : : /*
213 : : * If we restarted, our stderr is already redirected into our own input
214 : : * pipe. This is of course pretty useless, not to mention that it
215 : : * interferes with detecting pipe EOF. Point stderr to /dev/null. This
216 : : * assumes that all interesting messages generated in the syslogger will
217 : : * come through elog.c and will be sent to write_syslogger_file.
218 : : */
219 [ # # ]: 0 : if (redirection_done)
220 : : {
221 : 0 : int fd = open(DEVNULL, O_WRONLY, 0);
222 : :
223 : : /*
224 : : * The closes might look redundant, but they are not: we want to be
225 : : * darn sure the pipe gets closed even if the open failed. We can
226 : : * survive running with stderr pointing nowhere, but we can't afford
227 : : * to have extra pipe input descriptors hanging around.
228 : : *
229 : : * As we're just trying to reset these to go to DEVNULL, there's not
230 : : * much point in checking for failure from the close/dup2 calls here,
231 : : * if they fail then presumably the file descriptors are closed and
232 : : * any writes will go into the bitbucket anyway.
233 : : */
234 : 0 : close(STDOUT_FILENO);
235 : 0 : close(STDERR_FILENO);
236 [ # # ]: 0 : if (fd != -1)
237 : : {
238 : 0 : (void) dup2(fd, STDOUT_FILENO);
239 : 0 : (void) dup2(fd, STDERR_FILENO);
240 : 0 : close(fd);
241 : 0 : }
242 : 0 : }
243 : :
244 : : /*
245 : : * Syslogger's own stderr can't be the syslogPipe, so set it back to text
246 : : * mode if we didn't just close it. (It was set to binary in
247 : : * SubPostmasterMain).
248 : : */
249 : : #ifdef WIN32
250 : : else
251 : : _setmode(STDERR_FILENO, _O_TEXT);
252 : : #endif
253 : :
254 : : /*
255 : : * Also close our copy of the write end of the pipe. This is needed to
256 : : * ensure we can detect pipe EOF correctly. (But note that in the restart
257 : : * case, the postmaster already did this.)
258 : : */
259 : : #ifndef WIN32
260 [ # # ]: 0 : if (syslogPipe[1] >= 0)
261 : 0 : close(syslogPipe[1]);
262 : 0 : syslogPipe[1] = -1;
263 : : #else
264 : : if (syslogPipe[1])
265 : : CloseHandle(syslogPipe[1]);
266 : : syslogPipe[1] = 0;
267 : : #endif
268 : :
269 : : /*
270 : : * Properly accept or ignore signals the postmaster might send us
271 : : *
272 : : * Note: we ignore all termination signals, and instead exit only when all
273 : : * upstream processes are gone, to ensure we don't miss any dying gasps of
274 : : * broken backends...
275 : : */
276 : :
277 : 0 : pqsignal(SIGHUP, SignalHandlerForConfigReload); /* set flag to read config
278 : : * file */
279 : 0 : pqsignal(SIGINT, SIG_IGN);
280 : 0 : pqsignal(SIGTERM, SIG_IGN);
281 : 0 : pqsignal(SIGQUIT, SIG_IGN);
282 : 0 : pqsignal(SIGALRM, SIG_IGN);
283 : 0 : pqsignal(SIGPIPE, SIG_IGN);
284 : 0 : pqsignal(SIGUSR1, sigUsr1Handler); /* request log rotation */
285 : 0 : pqsignal(SIGUSR2, SIG_IGN);
286 : :
287 : : /*
288 : : * Reset some signals that are accepted by postmaster but not here
289 : : */
290 : 0 : pqsignal(SIGCHLD, SIG_DFL);
291 : :
292 : 0 : sigprocmask(SIG_SETMASK, &UnBlockSig, NULL);
293 : :
294 : : #ifdef WIN32
295 : : /* Fire up separate data transfer thread */
296 : : InitializeCriticalSection(&sysloggerSection);
297 : : EnterCriticalSection(&sysloggerSection);
298 : :
299 : : threadHandle = (HANDLE) _beginthreadex(NULL, 0, pipeThread, NULL, 0, NULL);
300 : : if (threadHandle == 0)
301 : : elog(FATAL, "could not create syslogger data transfer thread: %m");
302 : : #endif /* WIN32 */
303 : :
304 : : /*
305 : : * Remember active logfiles' name(s). We recompute 'em from the reference
306 : : * time because passing down just the pg_time_t is a lot cheaper than
307 : : * passing a whole file path in the EXEC_BACKEND case.
308 : : */
309 : 0 : last_sys_file_name = logfile_getname(first_syslogger_file_time, NULL);
310 [ # # ]: 0 : if (csvlogFile != NULL)
311 : 0 : last_csv_file_name = logfile_getname(first_syslogger_file_time, ".csv");
312 [ # # ]: 0 : if (jsonlogFile != NULL)
313 : 0 : last_json_file_name = logfile_getname(first_syslogger_file_time, ".json");
314 : :
315 : : /* remember active logfile parameters */
316 : 0 : currentLogDir = pstrdup(Log_directory);
317 : 0 : currentLogFilename = pstrdup(Log_filename);
318 : 0 : currentLogRotationAge = Log_RotationAge;
319 : : /* set next planned rotation time */
320 : 0 : set_next_rotation_time();
321 : 0 : update_metainfo_datafile();
322 : :
323 : : /*
324 : : * Reset whereToSendOutput, as the postmaster will do (but hasn't yet, at
325 : : * the point where we forked). This prevents duplicate output of messages
326 : : * from syslogger itself.
327 : : */
328 : 0 : whereToSendOutput = DestNone;
329 : :
330 : : /*
331 : : * Set up a reusable WaitEventSet object we'll use to wait for our latch,
332 : : * and (except on Windows) our socket.
333 : : *
334 : : * Unlike all other postmaster child processes, we'll ignore postmaster
335 : : * death because we want to collect final log output from all backends and
336 : : * then exit last. We'll do that by running until we see EOF on the
337 : : * syslog pipe, which implies that all other backends have exited
338 : : * (including the postmaster).
339 : : */
340 : 0 : wes = CreateWaitEventSet(NULL, 2);
341 : 0 : AddWaitEventToSet(wes, WL_LATCH_SET, PGINVALID_SOCKET, MyLatch, NULL);
342 : : #ifndef WIN32
343 : 0 : AddWaitEventToSet(wes, WL_SOCKET_READABLE, syslogPipe[0], NULL, NULL);
344 : : #endif
345 : :
346 : : /* main worker loop */
347 : 0 : for (;;)
348 : : {
349 : 0 : bool time_based_rotation = false;
350 : 0 : int size_rotation_for = 0;
351 : 0 : long cur_timeout;
352 : 0 : WaitEvent event;
353 : :
354 : : #ifndef WIN32
355 : 0 : int rc;
356 : : #endif
357 : :
358 : : /* Clear any already-pending wakeups */
359 : 0 : ResetLatch(MyLatch);
360 : :
361 : : /*
362 : : * Process any requests or signals received recently.
363 : : */
364 [ # # ]: 0 : if (ConfigReloadPending)
365 : : {
366 : 0 : ConfigReloadPending = false;
367 : 0 : ProcessConfigFile(PGC_SIGHUP);
368 : :
369 : : /*
370 : : * Check if the log directory or filename pattern changed in
371 : : * postgresql.conf. If so, force rotation to make sure we're
372 : : * writing the logfiles in the right place.
373 : : */
374 [ # # ]: 0 : if (strcmp(Log_directory, currentLogDir) != 0)
375 : : {
376 : 0 : pfree(currentLogDir);
377 : 0 : currentLogDir = pstrdup(Log_directory);
378 : 0 : rotation_requested = true;
379 : :
380 : : /*
381 : : * Also, create new directory if not present; ignore errors
382 : : */
383 : 0 : (void) MakePGDirectory(Log_directory);
384 : 0 : }
385 [ # # ]: 0 : if (strcmp(Log_filename, currentLogFilename) != 0)
386 : : {
387 : 0 : pfree(currentLogFilename);
388 : 0 : currentLogFilename = pstrdup(Log_filename);
389 : 0 : rotation_requested = true;
390 : 0 : }
391 : :
392 : : /*
393 : : * Force a rotation if CSVLOG output was just turned on or off and
394 : : * we need to open or close csvlogFile accordingly.
395 : : */
396 [ # # # # ]: 0 : if (((Log_destination & LOG_DESTINATION_CSVLOG) != 0) !=
397 : 0 : (csvlogFile != NULL))
398 : 0 : rotation_requested = true;
399 : :
400 : : /*
401 : : * Force a rotation if JSONLOG output was just turned on or off
402 : : * and we need to open or close jsonlogFile accordingly.
403 : : */
404 [ # # # # ]: 0 : if (((Log_destination & LOG_DESTINATION_JSONLOG) != 0) !=
405 : 0 : (jsonlogFile != NULL))
406 : 0 : rotation_requested = true;
407 : :
408 : : /*
409 : : * If rotation time parameter changed, reset next rotation time,
410 : : * but don't immediately force a rotation.
411 : : */
412 [ # # ]: 0 : if (currentLogRotationAge != Log_RotationAge)
413 : : {
414 : 0 : currentLogRotationAge = Log_RotationAge;
415 : 0 : set_next_rotation_time();
416 : 0 : }
417 : :
418 : : /*
419 : : * If we had a rotation-disabling failure, re-enable rotation
420 : : * attempts after SIGHUP, and force one immediately.
421 : : */
422 [ # # ]: 0 : if (rotation_disabled)
423 : : {
424 : 0 : rotation_disabled = false;
425 : 0 : rotation_requested = true;
426 : 0 : }
427 : :
428 : : /*
429 : : * Force rewriting last log filename when reloading configuration.
430 : : * Even if rotation_requested is false, log_destination may have
431 : : * been changed and we don't want to wait the next file rotation.
432 : : */
433 : 0 : update_metainfo_datafile();
434 : 0 : }
435 : :
436 [ # # # # ]: 0 : if (Log_RotationAge > 0 && !rotation_disabled)
437 : : {
438 : : /* Do a logfile rotation if it's time */
439 : 0 : now = (pg_time_t) time(NULL);
440 [ # # ]: 0 : if (now >= next_rotation_time)
441 : 0 : rotation_requested = time_based_rotation = true;
442 : 0 : }
443 : :
444 [ # # # # : 0 : if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
# # ]
445 : : {
446 : : /* Do a rotation if file is too big */
447 [ # # ]: 0 : if (ftello(syslogFile) >= Log_RotationSize * (pgoff_t) 1024)
448 : : {
449 : 0 : rotation_requested = true;
450 : 0 : size_rotation_for |= LOG_DESTINATION_STDERR;
451 : 0 : }
452 [ # # # # ]: 0 : if (csvlogFile != NULL &&
453 : 0 : ftello(csvlogFile) >= Log_RotationSize * (pgoff_t) 1024)
454 : : {
455 : 0 : rotation_requested = true;
456 : 0 : size_rotation_for |= LOG_DESTINATION_CSVLOG;
457 : 0 : }
458 [ # # # # ]: 0 : if (jsonlogFile != NULL &&
459 : 0 : ftello(jsonlogFile) >= Log_RotationSize * (pgoff_t) 1024)
460 : : {
461 : 0 : rotation_requested = true;
462 : 0 : size_rotation_for |= LOG_DESTINATION_JSONLOG;
463 : 0 : }
464 : 0 : }
465 : :
466 [ # # ]: 0 : if (rotation_requested)
467 : : {
468 : : /*
469 : : * Force rotation when both values are zero. It means the request
470 : : * was sent by pg_rotate_logfile() or "pg_ctl logrotate".
471 : : */
472 [ # # # # ]: 0 : if (!time_based_rotation && size_rotation_for == 0)
473 : 0 : size_rotation_for = LOG_DESTINATION_STDERR |
474 : : LOG_DESTINATION_CSVLOG |
475 : : LOG_DESTINATION_JSONLOG;
476 : 0 : logfile_rotate(time_based_rotation, size_rotation_for);
477 : 0 : }
478 : :
479 : : /*
480 : : * Calculate time till next time-based rotation, so that we don't
481 : : * sleep longer than that. We assume the value of "now" obtained
482 : : * above is still close enough. Note we can't make this calculation
483 : : * until after calling logfile_rotate(), since it will advance
484 : : * next_rotation_time.
485 : : *
486 : : * Also note that we need to beware of overflow in calculation of the
487 : : * timeout: with large settings of Log_RotationAge, next_rotation_time
488 : : * could be more than INT_MAX msec in the future. In that case we'll
489 : : * wait no more than INT_MAX msec, and try again.
490 : : */
491 [ # # # # ]: 0 : if (Log_RotationAge > 0 && !rotation_disabled)
492 : : {
493 : 0 : pg_time_t delay;
494 : :
495 : 0 : delay = next_rotation_time - now;
496 [ # # ]: 0 : if (delay > 0)
497 : : {
498 [ # # ]: 0 : if (delay > INT_MAX / 1000)
499 : 0 : delay = INT_MAX / 1000;
500 : 0 : cur_timeout = delay * 1000L; /* msec */
501 : 0 : }
502 : : else
503 : 0 : cur_timeout = 0;
504 : 0 : }
505 : : else
506 : 0 : cur_timeout = -1L;
507 : :
508 : : /*
509 : : * Sleep until there's something to do
510 : : */
511 : : #ifndef WIN32
512 : 0 : rc = WaitEventSetWait(wes, cur_timeout, &event, 1,
513 : : WAIT_EVENT_SYSLOGGER_MAIN);
514 : :
515 [ # # # # ]: 0 : if (rc == 1 && event.events == WL_SOCKET_READABLE)
516 : : {
517 : 0 : int bytesRead;
518 : :
519 : 0 : bytesRead = read(syslogPipe[0],
520 : 0 : logbuffer + bytes_in_logbuffer,
521 : 0 : sizeof(logbuffer) - bytes_in_logbuffer);
522 [ # # ]: 0 : if (bytesRead < 0)
523 : : {
524 [ # # ]: 0 : if (errno != EINTR)
525 [ # # # # ]: 0 : ereport(LOG,
526 : : (errcode_for_socket_access(),
527 : : errmsg("could not read from logger pipe: %m")));
528 : 0 : }
529 [ # # ]: 0 : else if (bytesRead > 0)
530 : : {
531 : 0 : bytes_in_logbuffer += bytesRead;
532 : 0 : process_pipe_input(logbuffer, &bytes_in_logbuffer);
533 : 0 : continue;
534 : : }
535 : : else
536 : : {
537 : : /*
538 : : * Zero bytes read when select() is saying read-ready means
539 : : * EOF on the pipe: that is, there are no longer any processes
540 : : * with the pipe write end open. Therefore, the postmaster
541 : : * and all backends are shut down, and we are done.
542 : : */
543 : 0 : pipe_eof_seen = true;
544 : :
545 : : /* if there's any data left then force it out now */
546 : 0 : flush_pipe_input(logbuffer, &bytes_in_logbuffer);
547 : : }
548 [ # # ]: 0 : }
549 : : #else /* WIN32 */
550 : :
551 : : /*
552 : : * On Windows we leave it to a separate thread to transfer data and
553 : : * detect pipe EOF. The main thread just wakes up to handle SIGHUP
554 : : * and rotation conditions.
555 : : *
556 : : * Server code isn't generally thread-safe, so we ensure that only one
557 : : * of the threads is active at a time by entering the critical section
558 : : * whenever we're not sleeping.
559 : : */
560 : : LeaveCriticalSection(&sysloggerSection);
561 : :
562 : : (void) WaitEventSetWait(wes, cur_timeout, &event, 1,
563 : : WAIT_EVENT_SYSLOGGER_MAIN);
564 : :
565 : : EnterCriticalSection(&sysloggerSection);
566 : : #endif /* WIN32 */
567 : :
568 [ # # ]: 0 : if (pipe_eof_seen)
569 : : {
570 : : /*
571 : : * seeing this message on the real stderr is annoying - so we make
572 : : * it DEBUG1 to suppress in normal use.
573 : : */
574 [ # # # # ]: 0 : ereport(DEBUG1,
575 : : (errmsg_internal("logger shutting down")));
576 : :
577 : : /*
578 : : * Normal exit from the syslogger is here. Note that we
579 : : * deliberately do not close syslogFile before exiting; this is to
580 : : * allow for the possibility of elog messages being generated
581 : : * inside proc_exit. Regular exit() will take care of flushing
582 : : * and closing stdio channels.
583 : : */
584 : 0 : proc_exit(0);
585 : : }
586 [ # # # ]: 0 : }
587 : : }
588 : :
589 : : /*
590 : : * Postmaster subroutine to start a syslogger subprocess.
591 : : */
592 : : int
593 : 0 : SysLogger_Start(int child_slot)
594 : : {
595 : 0 : pid_t sysloggerPid;
596 : 0 : char *filename;
597 : : #ifdef EXEC_BACKEND
598 : : SysloggerStartupData startup_data;
599 : : #endif /* EXEC_BACKEND */
600 : :
601 [ # # ]: 0 : Assert(Logging_collector);
602 : :
603 : : /*
604 : : * If first time through, create the pipe which will receive stderr
605 : : * output.
606 : : *
607 : : * If the syslogger crashes and needs to be restarted, we continue to use
608 : : * the same pipe (indeed must do so, since extant backends will be writing
609 : : * into that pipe).
610 : : *
611 : : * This means the postmaster must continue to hold the read end of the
612 : : * pipe open, so we can pass it down to the reincarnated syslogger. This
613 : : * is a bit klugy but we have little choice.
614 : : *
615 : : * Also note that we don't bother counting the pipe FDs by calling
616 : : * Reserve/ReleaseExternalFD. There's no real need to account for them
617 : : * accurately in the postmaster or syslogger process, and both ends of the
618 : : * pipe will wind up closed in all other postmaster children.
619 : : */
620 : : #ifndef WIN32
621 [ # # ]: 0 : if (syslogPipe[0] < 0)
622 : : {
623 [ # # ]: 0 : if (pipe(syslogPipe) < 0)
624 [ # # # # ]: 0 : ereport(FATAL,
625 : : (errcode_for_socket_access(),
626 : : errmsg("could not create pipe for syslog: %m")));
627 : 0 : }
628 : : #else
629 : : if (!syslogPipe[0])
630 : : {
631 : : SECURITY_ATTRIBUTES sa;
632 : :
633 : : memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
634 : : sa.nLength = sizeof(SECURITY_ATTRIBUTES);
635 : : sa.bInheritHandle = TRUE;
636 : :
637 : : if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
638 : : ereport(FATAL,
639 : : (errcode_for_file_access(),
640 : : errmsg("could not create pipe for syslog: %m")));
641 : : }
642 : : #endif
643 : :
644 : : /*
645 : : * Create log directory if not present; ignore errors
646 : : */
647 : 0 : (void) MakePGDirectory(Log_directory);
648 : :
649 : : /*
650 : : * The initial logfile is created right in the postmaster, to verify that
651 : : * the Log_directory is writable. We save the reference time so that the
652 : : * syslogger child process can recompute this file name.
653 : : *
654 : : * It might look a bit strange to re-do this during a syslogger restart,
655 : : * but we must do so since the postmaster closed syslogFile after the
656 : : * previous fork (and remembering that old file wouldn't be right anyway).
657 : : * Note we always append here, we won't overwrite any existing file. This
658 : : * is consistent with the normal rules, because by definition this is not
659 : : * a time-based rotation.
660 : : */
661 : 0 : first_syslogger_file_time = time(NULL);
662 : :
663 : 0 : filename = logfile_getname(first_syslogger_file_time, NULL);
664 : :
665 : 0 : syslogFile = logfile_open(filename, "a", false);
666 : :
667 : 0 : pfree(filename);
668 : :
669 : : /*
670 : : * Likewise for the initial CSV log file, if that's enabled. (Note that
671 : : * we open syslogFile even when only CSV output is nominally enabled,
672 : : * since some code paths will write to syslogFile anyway.)
673 : : */
674 [ # # ]: 0 : if (Log_destination & LOG_DESTINATION_CSVLOG)
675 : : {
676 : 0 : filename = logfile_getname(first_syslogger_file_time, ".csv");
677 : :
678 : 0 : csvlogFile = logfile_open(filename, "a", false);
679 : :
680 : 0 : pfree(filename);
681 : 0 : }
682 : :
683 : : /*
684 : : * Likewise for the initial JSON log file, if that's enabled. (Note that
685 : : * we open syslogFile even when only JSON output is nominally enabled,
686 : : * since some code paths will write to syslogFile anyway.)
687 : : */
688 [ # # ]: 0 : if (Log_destination & LOG_DESTINATION_JSONLOG)
689 : : {
690 : 0 : filename = logfile_getname(first_syslogger_file_time, ".json");
691 : :
692 : 0 : jsonlogFile = logfile_open(filename, "a", false);
693 : :
694 : 0 : pfree(filename);
695 : 0 : }
696 : :
697 : : #ifdef EXEC_BACKEND
698 : : startup_data.syslogFile = syslogger_fdget(syslogFile);
699 : : startup_data.csvlogFile = syslogger_fdget(csvlogFile);
700 : : startup_data.jsonlogFile = syslogger_fdget(jsonlogFile);
701 : : sysloggerPid = postmaster_child_launch(B_LOGGER, child_slot,
702 : : &startup_data, sizeof(startup_data), NULL);
703 : : #else
704 : 0 : sysloggerPid = postmaster_child_launch(B_LOGGER, child_slot,
705 : : NULL, 0, NULL);
706 : : #endif /* EXEC_BACKEND */
707 : :
708 [ # # ]: 0 : if (sysloggerPid == -1)
709 : : {
710 [ # # # # ]: 0 : ereport(LOG,
711 : : (errmsg("could not fork system logger: %m")));
712 : 0 : return 0;
713 : : }
714 : :
715 : : /* success, in postmaster */
716 : :
717 : : /* now we redirect stderr, if not done already */
718 [ # # ]: 0 : if (!redirection_done)
719 : : {
720 : : #ifdef WIN32
721 : : int fd;
722 : : #endif
723 : :
724 : : /*
725 : : * Leave a breadcrumb trail when redirecting, in case the user forgets
726 : : * that redirection is active and looks only at the original stderr
727 : : * target file.
728 : : */
729 [ # # # # ]: 0 : ereport(LOG,
730 : : (errmsg("redirecting log output to logging collector process"),
731 : : errhint("Future log output will appear in directory \"%s\".",
732 : : Log_directory)));
733 : :
734 : : #ifndef WIN32
735 : 0 : fflush(stdout);
736 [ # # ]: 0 : if (dup2(syslogPipe[1], STDOUT_FILENO) < 0)
737 [ # # # # ]: 0 : ereport(FATAL,
738 : : (errcode_for_file_access(),
739 : : errmsg("could not redirect stdout: %m")));
740 : 0 : fflush(stderr);
741 [ # # ]: 0 : if (dup2(syslogPipe[1], STDERR_FILENO) < 0)
742 [ # # # # ]: 0 : ereport(FATAL,
743 : : (errcode_for_file_access(),
744 : : errmsg("could not redirect stderr: %m")));
745 : : /* Now we are done with the write end of the pipe. */
746 : 0 : close(syslogPipe[1]);
747 : 0 : syslogPipe[1] = -1;
748 : : #else
749 : :
750 : : /*
751 : : * open the pipe in binary mode and make sure stderr is binary after
752 : : * it's been dup'ed into, to avoid disturbing the pipe chunking
753 : : * protocol.
754 : : */
755 : : fflush(stderr);
756 : : fd = _open_osfhandle((intptr_t) syslogPipe[1],
757 : : _O_APPEND | _O_BINARY);
758 : : if (dup2(fd, STDERR_FILENO) < 0)
759 : : ereport(FATAL,
760 : : (errcode_for_file_access(),
761 : : errmsg("could not redirect stderr: %m")));
762 : : close(fd);
763 : : _setmode(STDERR_FILENO, _O_BINARY);
764 : :
765 : : /*
766 : : * Now we are done with the write end of the pipe. CloseHandle() must
767 : : * not be called because the preceding close() closes the underlying
768 : : * handle.
769 : : */
770 : : syslogPipe[1] = 0;
771 : : #endif
772 : 0 : redirection_done = true;
773 : 0 : }
774 : :
775 : : /* postmaster will never write the file(s); close 'em */
776 : 0 : fclose(syslogFile);
777 : 0 : syslogFile = NULL;
778 [ # # ]: 0 : if (csvlogFile != NULL)
779 : : {
780 : 0 : fclose(csvlogFile);
781 : 0 : csvlogFile = NULL;
782 : 0 : }
783 [ # # ]: 0 : if (jsonlogFile != NULL)
784 : : {
785 : 0 : fclose(jsonlogFile);
786 : 0 : jsonlogFile = NULL;
787 : 0 : }
788 : 0 : return (int) sysloggerPid;
789 : 0 : }
790 : :
791 : :
792 : : #ifdef EXEC_BACKEND
793 : :
794 : : /*
795 : : * syslogger_fdget() -
796 : : *
797 : : * Utility wrapper to grab the file descriptor of an opened error output
798 : : * file. Used when building the command to fork the logging collector.
799 : : */
800 : : static int
801 : : syslogger_fdget(FILE *file)
802 : : {
803 : : #ifndef WIN32
804 : : if (file != NULL)
805 : : return fileno(file);
806 : : else
807 : : return -1;
808 : : #else
809 : : if (file != NULL)
810 : : return (int) _get_osfhandle(_fileno(file));
811 : : else
812 : : return 0;
813 : : #endif /* WIN32 */
814 : : }
815 : :
816 : : /*
817 : : * syslogger_fdopen() -
818 : : *
819 : : * Utility wrapper to re-open an error output file, using the given file
820 : : * descriptor. Used when parsing arguments in a forked logging collector.
821 : : */
822 : : static FILE *
823 : : syslogger_fdopen(int fd)
824 : : {
825 : : FILE *file = NULL;
826 : :
827 : : #ifndef WIN32
828 : : if (fd != -1)
829 : : {
830 : : file = fdopen(fd, "a");
831 : : setvbuf(file, NULL, PG_IOLBF, 0);
832 : : }
833 : : #else /* WIN32 */
834 : : if (fd != 0)
835 : : {
836 : : fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
837 : : if (fd > 0)
838 : : {
839 : : file = fdopen(fd, "a");
840 : : setvbuf(file, NULL, PG_IOLBF, 0);
841 : : }
842 : : }
843 : : #endif /* WIN32 */
844 : :
845 : : return file;
846 : : }
847 : : #endif /* EXEC_BACKEND */
848 : :
849 : :
850 : : /* --------------------------------
851 : : * pipe protocol handling
852 : : * --------------------------------
853 : : */
854 : :
855 : : /*
856 : : * Process data received through the syslogger pipe.
857 : : *
858 : : * This routine interprets the log pipe protocol which sends log messages as
859 : : * (hopefully atomic) chunks - such chunks are detected and reassembled here.
860 : : *
861 : : * The protocol has a header that starts with two nul bytes, then has a 16 bit
862 : : * length, the pid of the sending process, and a flag to indicate if it is
863 : : * the last chunk in a message. Incomplete chunks are saved until we read some
864 : : * more, and non-final chunks are accumulated until we get the final chunk.
865 : : *
866 : : * All of this is to avoid 2 problems:
867 : : * . partial messages being written to logfiles (messes rotation), and
868 : : * . messages from different backends being interleaved (messages garbled).
869 : : *
870 : : * Any non-protocol messages are written out directly. These should only come
871 : : * from non-PostgreSQL sources, however (e.g. third party libraries writing to
872 : : * stderr).
873 : : *
874 : : * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
875 : : * of bytes present. On exit, any not-yet-eaten data is left-justified in
876 : : * logbuffer, and *bytes_in_logbuffer is updated.
877 : : */
878 : : static void
879 : 0 : process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
880 : : {
881 : 0 : char *cursor = logbuffer;
882 : 0 : int count = *bytes_in_logbuffer;
883 : 0 : int dest = LOG_DESTINATION_STDERR;
884 : :
885 : : /* While we have enough for a header, process data... */
886 [ # # ]: 0 : while (count >= (int) (offsetof(PipeProtoHeader, data) + 1))
887 : : {
888 : 0 : PipeProtoHeader p;
889 : 0 : int chunklen;
890 : 0 : bits8 dest_flags;
891 : :
892 : : /* Do we have a valid header? */
893 : 0 : memcpy(&p, cursor, offsetof(PipeProtoHeader, data));
894 : 0 : dest_flags = p.flags & (PIPE_PROTO_DEST_STDERR |
895 : : PIPE_PROTO_DEST_CSVLOG |
896 : : PIPE_PROTO_DEST_JSONLOG);
897 [ # # # # ]: 0 : if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
898 [ # # # # ]: 0 : p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
899 [ # # # # ]: 0 : p.pid != 0 &&
900 : 0 : pg_number_of_ones[dest_flags] == 1)
901 : : {
902 : 0 : List *buffer_list;
903 : 0 : ListCell *cell;
904 : 0 : save_buffer *existing_slot = NULL,
905 : 0 : *free_slot = NULL;
906 : 0 : StringInfo str;
907 : :
908 : 0 : chunklen = PIPE_HEADER_SIZE + p.len;
909 : :
910 : : /* Fall out of loop if we don't have the whole chunk yet */
911 [ # # ]: 0 : if (count < chunklen)
912 : 0 : break;
913 : :
914 [ # # ]: 0 : if ((p.flags & PIPE_PROTO_DEST_STDERR) != 0)
915 : 0 : dest = LOG_DESTINATION_STDERR;
916 [ # # ]: 0 : else if ((p.flags & PIPE_PROTO_DEST_CSVLOG) != 0)
917 : 0 : dest = LOG_DESTINATION_CSVLOG;
918 [ # # ]: 0 : else if ((p.flags & PIPE_PROTO_DEST_JSONLOG) != 0)
919 : 0 : dest = LOG_DESTINATION_JSONLOG;
920 : : else
921 : : {
922 : : /* this should never happen as of the header validation */
923 : 0 : Assert(false);
924 : : }
925 : :
926 : : /* Locate any existing buffer for this source pid */
927 : 0 : buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
928 [ # # # # : 0 : foreach(cell, buffer_list)
# # ]
929 : : {
930 : 0 : save_buffer *buf = (save_buffer *) lfirst(cell);
931 : :
932 [ # # ]: 0 : if (buf->pid == p.pid)
933 : : {
934 : 0 : existing_slot = buf;
935 : 0 : break;
936 : : }
937 [ # # # # ]: 0 : if (buf->pid == 0 && free_slot == NULL)
938 : 0 : free_slot = buf;
939 [ # # ]: 0 : }
940 : :
941 [ # # ]: 0 : if ((p.flags & PIPE_PROTO_IS_LAST) == 0)
942 : : {
943 : : /*
944 : : * Save a complete non-final chunk in a per-pid buffer
945 : : */
946 [ # # ]: 0 : if (existing_slot != NULL)
947 : : {
948 : : /* Add chunk to data from preceding chunks */
949 : 0 : str = &(existing_slot->data);
950 : 0 : appendBinaryStringInfo(str,
951 : 0 : cursor + PIPE_HEADER_SIZE,
952 : 0 : p.len);
953 : 0 : }
954 : : else
955 : : {
956 : : /* First chunk of message, save in a new buffer */
957 [ # # ]: 0 : if (free_slot == NULL)
958 : : {
959 : : /*
960 : : * Need a free slot, but there isn't one in the list,
961 : : * so create a new one and extend the list with it.
962 : : */
963 : 0 : free_slot = palloc_object(save_buffer);
964 : 0 : buffer_list = lappend(buffer_list, free_slot);
965 : 0 : buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
966 : 0 : }
967 : 0 : free_slot->pid = p.pid;
968 : 0 : str = &(free_slot->data);
969 : 0 : initStringInfo(str);
970 : 0 : appendBinaryStringInfo(str,
971 : 0 : cursor + PIPE_HEADER_SIZE,
972 : 0 : p.len);
973 : : }
974 : 0 : }
975 : : else
976 : : {
977 : : /*
978 : : * Final chunk --- add it to anything saved for that pid, and
979 : : * either way write the whole thing out.
980 : : */
981 [ # # ]: 0 : if (existing_slot != NULL)
982 : : {
983 : 0 : str = &(existing_slot->data);
984 : 0 : appendBinaryStringInfo(str,
985 : 0 : cursor + PIPE_HEADER_SIZE,
986 : 0 : p.len);
987 : 0 : write_syslogger_file(str->data, str->len, dest);
988 : : /* Mark the buffer unused, and reclaim string storage */
989 : 0 : existing_slot->pid = 0;
990 : 0 : pfree(str->data);
991 : 0 : }
992 : : else
993 : : {
994 : : /* The whole message was one chunk, evidently. */
995 : 0 : write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
996 : 0 : dest);
997 : : }
998 : : }
999 : :
1000 : : /* Finished processing this chunk */
1001 : 0 : cursor += chunklen;
1002 : 0 : count -= chunklen;
1003 [ # # ]: 0 : }
1004 : : else
1005 : : {
1006 : : /* Process non-protocol data */
1007 : :
1008 : : /*
1009 : : * Look for the start of a protocol header. If found, dump data
1010 : : * up to there and repeat the loop. Otherwise, dump it all and
1011 : : * fall out of the loop. (Note: we want to dump it all if at all
1012 : : * possible, so as to avoid dividing non-protocol messages across
1013 : : * logfiles. We expect that in many scenarios, a non-protocol
1014 : : * message will arrive all in one read(), and we want to respect
1015 : : * the read() boundary if possible.)
1016 : : */
1017 [ # # ]: 0 : for (chunklen = 1; chunklen < count; chunklen++)
1018 : : {
1019 [ # # ]: 0 : if (cursor[chunklen] == '\0')
1020 : 0 : break;
1021 : 0 : }
1022 : : /* fall back on the stderr log as the destination */
1023 : 0 : write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
1024 : 0 : cursor += chunklen;
1025 : 0 : count -= chunklen;
1026 : : }
1027 [ # # # ]: 0 : }
1028 : :
1029 : : /* We don't have a full chunk, so left-align what remains in the buffer */
1030 [ # # # # ]: 0 : if (count > 0 && cursor != logbuffer)
1031 : 0 : memmove(logbuffer, cursor, count);
1032 : 0 : *bytes_in_logbuffer = count;
1033 : 0 : }
1034 : :
1035 : : /*
1036 : : * Force out any buffered data
1037 : : *
1038 : : * This is currently used only at syslogger shutdown, but could perhaps be
1039 : : * useful at other times, so it is careful to leave things in a clean state.
1040 : : */
1041 : : static void
1042 : 0 : flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
1043 : : {
1044 : 0 : int i;
1045 : :
1046 : : /* Dump any incomplete protocol messages */
1047 [ # # ]: 0 : for (i = 0; i < NBUFFER_LISTS; i++)
1048 : : {
1049 : 0 : List *list = buffer_lists[i];
1050 : 0 : ListCell *cell;
1051 : :
1052 [ # # # # : 0 : foreach(cell, list)
# # ]
1053 : : {
1054 : 0 : save_buffer *buf = (save_buffer *) lfirst(cell);
1055 : :
1056 [ # # ]: 0 : if (buf->pid != 0)
1057 : : {
1058 : 0 : StringInfo str = &(buf->data);
1059 : :
1060 : 0 : write_syslogger_file(str->data, str->len,
1061 : : LOG_DESTINATION_STDERR);
1062 : : /* Mark the buffer unused, and reclaim string storage */
1063 : 0 : buf->pid = 0;
1064 : 0 : pfree(str->data);
1065 : 0 : }
1066 : 0 : }
1067 : 0 : }
1068 : :
1069 : : /*
1070 : : * Force out any remaining pipe data as-is; we don't bother trying to
1071 : : * remove any protocol headers that may exist in it.
1072 : : */
1073 [ # # ]: 0 : if (*bytes_in_logbuffer > 0)
1074 : 0 : write_syslogger_file(logbuffer, *bytes_in_logbuffer,
1075 : : LOG_DESTINATION_STDERR);
1076 : 0 : *bytes_in_logbuffer = 0;
1077 : 0 : }
1078 : :
1079 : :
1080 : : /* --------------------------------
1081 : : * logfile routines
1082 : : * --------------------------------
1083 : : */
1084 : :
1085 : : /*
1086 : : * Write text to the currently open logfile
1087 : : *
1088 : : * This is exported so that elog.c can call it when MyBackendType is B_LOGGER.
1089 : : * This allows the syslogger process to record elog messages of its own,
1090 : : * even though its stderr does not point at the syslog pipe.
1091 : : */
1092 : : void
1093 : 0 : write_syslogger_file(const char *buffer, int count, int destination)
1094 : : {
1095 : 0 : int rc;
1096 : 0 : FILE *logfile;
1097 : :
1098 : : /*
1099 : : * If we're told to write to a structured log file, but it's not open,
1100 : : * dump the data to syslogFile (which is always open) instead. This can
1101 : : * happen if structured output is enabled after postmaster start and we've
1102 : : * been unable to open logFile. There are also race conditions during a
1103 : : * parameter change whereby backends might send us structured output
1104 : : * before we open the logFile or after we close it. Writing formatted
1105 : : * output to the regular log file isn't great, but it beats dropping log
1106 : : * output on the floor.
1107 : : *
1108 : : * Think not to improve this by trying to open logFile on-the-fly. Any
1109 : : * failure in that would lead to recursion.
1110 : : */
1111 [ # # # # ]: 0 : if ((destination & LOG_DESTINATION_CSVLOG) && csvlogFile != NULL)
1112 : 0 : logfile = csvlogFile;
1113 [ # # # # ]: 0 : else if ((destination & LOG_DESTINATION_JSONLOG) && jsonlogFile != NULL)
1114 : 0 : logfile = jsonlogFile;
1115 : : else
1116 : 0 : logfile = syslogFile;
1117 : :
1118 : 0 : rc = fwrite(buffer, 1, count, logfile);
1119 : :
1120 : : /*
1121 : : * Try to report any failure. We mustn't use ereport because it would
1122 : : * just recurse right back here, but write_stderr is OK: it will write
1123 : : * either to the postmaster's original stderr, or to /dev/null, but never
1124 : : * to our input pipe which would result in a different sort of looping.
1125 : : */
1126 [ # # ]: 0 : if (rc != count)
1127 : 0 : write_stderr("could not write to log file: %m\n");
1128 : 0 : }
1129 : :
1130 : : #ifdef WIN32
1131 : :
1132 : : /*
1133 : : * Worker thread to transfer data from the pipe to the current logfile.
1134 : : *
1135 : : * We need this because on Windows, WaitForMultipleObjects does not work on
1136 : : * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
1137 : : * allow for SIGHUP; and select is for sockets only.
1138 : : */
1139 : : static unsigned int __stdcall
1140 : : pipeThread(void *arg)
1141 : : {
1142 : : char logbuffer[READ_BUF_SIZE];
1143 : : int bytes_in_logbuffer = 0;
1144 : :
1145 : : for (;;)
1146 : : {
1147 : : DWORD bytesRead;
1148 : : BOOL result;
1149 : :
1150 : : result = ReadFile(syslogPipe[0],
1151 : : logbuffer + bytes_in_logbuffer,
1152 : : sizeof(logbuffer) - bytes_in_logbuffer,
1153 : : &bytesRead, 0);
1154 : :
1155 : : /*
1156 : : * Enter critical section before doing anything that might touch
1157 : : * global state shared by the main thread. Anything that uses
1158 : : * palloc()/pfree() in particular are not safe outside the critical
1159 : : * section.
1160 : : */
1161 : : EnterCriticalSection(&sysloggerSection);
1162 : : if (!result)
1163 : : {
1164 : : DWORD error = GetLastError();
1165 : :
1166 : : if (error == ERROR_HANDLE_EOF ||
1167 : : error == ERROR_BROKEN_PIPE)
1168 : : break;
1169 : : _dosmaperr(error);
1170 : : ereport(LOG,
1171 : : (errcode_for_file_access(),
1172 : : errmsg("could not read from logger pipe: %m")));
1173 : : }
1174 : : else if (bytesRead > 0)
1175 : : {
1176 : : bytes_in_logbuffer += bytesRead;
1177 : : process_pipe_input(logbuffer, &bytes_in_logbuffer);
1178 : : }
1179 : :
1180 : : /*
1181 : : * If we've filled the current logfile, nudge the main thread to do a
1182 : : * log rotation.
1183 : : */
1184 : : if (Log_RotationSize > 0)
1185 : : {
1186 : : if (ftello(syslogFile) >= Log_RotationSize * (pgoff_t) 1024 ||
1187 : : (csvlogFile != NULL &&
1188 : : ftello(csvlogFile) >= Log_RotationSize * (pgoff_t) 1024) ||
1189 : : (jsonlogFile != NULL &&
1190 : : ftello(jsonlogFile) >= Log_RotationSize * (pgoff_t) 1024))
1191 : : SetLatch(MyLatch);
1192 : : }
1193 : : LeaveCriticalSection(&sysloggerSection);
1194 : : }
1195 : :
1196 : : /* We exit the above loop only upon detecting pipe EOF */
1197 : : pipe_eof_seen = true;
1198 : :
1199 : : /* if there's any data left then force it out now */
1200 : : flush_pipe_input(logbuffer, &bytes_in_logbuffer);
1201 : :
1202 : : /* set the latch to waken the main thread, which will quit */
1203 : : SetLatch(MyLatch);
1204 : :
1205 : : LeaveCriticalSection(&sysloggerSection);
1206 : : _endthread();
1207 : : return 0;
1208 : : }
1209 : : #endif /* WIN32 */
1210 : :
1211 : : /*
1212 : : * Open a new logfile with proper permissions and buffering options.
1213 : : *
1214 : : * If allow_errors is true, we just log any open failure and return NULL
1215 : : * (with errno still correct for the fopen failure).
1216 : : * Otherwise, errors are treated as fatal.
1217 : : */
1218 : : static FILE *
1219 : 0 : logfile_open(const char *filename, const char *mode, bool allow_errors)
1220 : : {
1221 : 0 : FILE *fh;
1222 : 0 : mode_t oumask;
1223 : :
1224 : : /*
1225 : : * Note we do not let Log_file_mode disable IWUSR, since we certainly want
1226 : : * to be able to write the files ourselves.
1227 : : */
1228 : 0 : oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
1229 : 0 : fh = fopen(filename, mode);
1230 : 0 : umask(oumask);
1231 : :
1232 [ # # ]: 0 : if (fh)
1233 : : {
1234 : 0 : setvbuf(fh, NULL, PG_IOLBF, 0);
1235 : :
1236 : : #ifdef WIN32
1237 : : /* use CRLF line endings on Windows */
1238 : : _setmode(_fileno(fh), _O_TEXT);
1239 : : #endif
1240 : 0 : }
1241 : : else
1242 : : {
1243 : 0 : int save_errno = errno;
1244 : :
1245 [ # # # # : 0 : ereport(allow_errors ? LOG : FATAL,
# # # # #
# ]
1246 : : (errcode_for_file_access(),
1247 : : errmsg("could not open log file \"%s\": %m",
1248 : : filename)));
1249 : 0 : errno = save_errno;
1250 : 0 : }
1251 : :
1252 : 0 : return fh;
1253 : 0 : }
1254 : :
1255 : : /*
1256 : : * Do logfile rotation for a single destination, as specified by target_dest.
1257 : : * The information stored in *last_file_name and *logFile is updated on a
1258 : : * successful file rotation.
1259 : : *
1260 : : * Returns false if the rotation has been stopped, or true to move on to
1261 : : * the processing of other formats.
1262 : : */
1263 : : static bool
1264 : 0 : logfile_rotate_dest(bool time_based_rotation, int size_rotation_for,
1265 : : pg_time_t fntime, int target_dest,
1266 : : char **last_file_name, FILE **logFile)
1267 : : {
1268 : 0 : char *logFileExt = NULL;
1269 : 0 : char *filename;
1270 : 0 : FILE *fh;
1271 : :
1272 : : /*
1273 : : * If the target destination was just turned off, close the previous file
1274 : : * and unregister its data. This cannot happen for stderr as syslogFile
1275 : : * is assumed to be always opened even if stderr is disabled in
1276 : : * log_destination.
1277 : : */
1278 [ # # # # ]: 0 : if ((Log_destination & target_dest) == 0 &&
1279 : 0 : target_dest != LOG_DESTINATION_STDERR)
1280 : : {
1281 [ # # ]: 0 : if (*logFile != NULL)
1282 : 0 : fclose(*logFile);
1283 : 0 : *logFile = NULL;
1284 [ # # ]: 0 : if (*last_file_name != NULL)
1285 : 0 : pfree(*last_file_name);
1286 : 0 : *last_file_name = NULL;
1287 : 0 : return true;
1288 : : }
1289 : :
1290 : : /*
1291 : : * Leave if it is not time for a rotation or if the target destination has
1292 : : * no need to do a rotation based on the size of its file.
1293 : : */
1294 [ # # # # ]: 0 : if (!time_based_rotation && (size_rotation_for & target_dest) == 0)
1295 : 0 : return true;
1296 : :
1297 : : /* file extension depends on the destination type */
1298 [ # # ]: 0 : if (target_dest == LOG_DESTINATION_STDERR)
1299 : 0 : logFileExt = NULL;
1300 [ # # ]: 0 : else if (target_dest == LOG_DESTINATION_CSVLOG)
1301 : 0 : logFileExt = ".csv";
1302 [ # # ]: 0 : else if (target_dest == LOG_DESTINATION_JSONLOG)
1303 : 0 : logFileExt = ".json";
1304 : : else
1305 : : {
1306 : : /* cannot happen */
1307 : 0 : Assert(false);
1308 : : }
1309 : :
1310 : : /* build the new file name */
1311 : 0 : filename = logfile_getname(fntime, logFileExt);
1312 : :
1313 : : /*
1314 : : * Decide whether to overwrite or append. We can overwrite if (a)
1315 : : * Log_truncate_on_rotation is set, (b) the rotation was triggered by
1316 : : * elapsed time and not something else, and (c) the computed file name is
1317 : : * different from what we were previously logging into.
1318 : : */
1319 [ # # # # ]: 0 : if (Log_truncate_on_rotation && time_based_rotation &&
1320 [ # # # # ]: 0 : *last_file_name != NULL &&
1321 : 0 : strcmp(filename, *last_file_name) != 0)
1322 : 0 : fh = logfile_open(filename, "w", true);
1323 : : else
1324 : 0 : fh = logfile_open(filename, "a", true);
1325 : :
1326 [ # # ]: 0 : if (!fh)
1327 : : {
1328 : : /*
1329 : : * ENFILE/EMFILE are not too surprising on a busy system; just keep
1330 : : * using the old file till we manage to get a new one. Otherwise,
1331 : : * assume something's wrong with Log_directory and stop trying to
1332 : : * create files.
1333 : : */
1334 [ # # # # ]: 0 : if (errno != ENFILE && errno != EMFILE)
1335 : : {
1336 [ # # # # ]: 0 : ereport(LOG,
1337 : : (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1338 : 0 : rotation_disabled = true;
1339 : 0 : }
1340 : :
1341 [ # # ]: 0 : if (filename)
1342 : 0 : pfree(filename);
1343 : 0 : return false;
1344 : : }
1345 : :
1346 : : /* fill in the new information */
1347 [ # # ]: 0 : if (*logFile != NULL)
1348 : 0 : fclose(*logFile);
1349 : 0 : *logFile = fh;
1350 : :
1351 : : /* instead of pfree'ing filename, remember it for next time */
1352 [ # # ]: 0 : if (*last_file_name != NULL)
1353 : 0 : pfree(*last_file_name);
1354 : 0 : *last_file_name = filename;
1355 : :
1356 : 0 : return true;
1357 : 0 : }
1358 : :
1359 : : /*
1360 : : * perform logfile rotation
1361 : : */
1362 : : static void
1363 : 0 : logfile_rotate(bool time_based_rotation, int size_rotation_for)
1364 : : {
1365 : 0 : pg_time_t fntime;
1366 : :
1367 : 0 : rotation_requested = false;
1368 : :
1369 : : /*
1370 : : * When doing a time-based rotation, invent the new logfile name based on
1371 : : * the planned rotation time, not current time, to avoid "slippage" in the
1372 : : * file name when we don't do the rotation immediately.
1373 : : */
1374 [ # # ]: 0 : if (time_based_rotation)
1375 : 0 : fntime = next_rotation_time;
1376 : : else
1377 : 0 : fntime = time(NULL);
1378 : :
1379 : : /* file rotation for stderr */
1380 [ # # ]: 0 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1381 : : LOG_DESTINATION_STDERR, &last_sys_file_name,
1382 : : &syslogFile))
1383 : 0 : return;
1384 : :
1385 : : /* file rotation for csvlog */
1386 [ # # ]: 0 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1387 : : LOG_DESTINATION_CSVLOG, &last_csv_file_name,
1388 : : &csvlogFile))
1389 : 0 : return;
1390 : :
1391 : : /* file rotation for jsonlog */
1392 [ # # ]: 0 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1393 : : LOG_DESTINATION_JSONLOG, &last_json_file_name,
1394 : : &jsonlogFile))
1395 : 0 : return;
1396 : :
1397 : 0 : update_metainfo_datafile();
1398 : :
1399 : 0 : set_next_rotation_time();
1400 [ # # ]: 0 : }
1401 : :
1402 : :
1403 : : /*
1404 : : * construct logfile name using timestamp information
1405 : : *
1406 : : * If suffix isn't NULL, append it to the name, replacing any ".log"
1407 : : * that may be in the pattern.
1408 : : *
1409 : : * Result is palloc'd.
1410 : : */
1411 : : static char *
1412 : 0 : logfile_getname(pg_time_t timestamp, const char *suffix)
1413 : : {
1414 : 0 : char *filename;
1415 : 0 : int len;
1416 : :
1417 : 0 : filename = palloc(MAXPGPATH);
1418 : :
1419 : 0 : snprintf(filename, MAXPGPATH, "%s/", Log_directory);
1420 : :
1421 : 0 : len = strlen(filename);
1422 : :
1423 : : /* treat Log_filename as a strftime pattern */
1424 : 0 : pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
1425 : 0 : pg_localtime(×tamp, log_timezone));
1426 : :
1427 [ # # ]: 0 : if (suffix != NULL)
1428 : : {
1429 : 0 : len = strlen(filename);
1430 [ # # # # ]: 0 : if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
1431 : 0 : len -= 4;
1432 : 0 : strlcpy(filename + len, suffix, MAXPGPATH - len);
1433 : 0 : }
1434 : :
1435 : 0 : return filename;
1436 : 0 : }
1437 : :
1438 : : /*
1439 : : * Determine the next planned rotation time, and store in next_rotation_time.
1440 : : */
1441 : : static void
1442 : 0 : set_next_rotation_time(void)
1443 : : {
1444 : 0 : pg_time_t now;
1445 : 0 : struct pg_tm *tm;
1446 : 0 : int rotinterval;
1447 : :
1448 : : /* nothing to do if time-based rotation is disabled */
1449 [ # # ]: 0 : if (Log_RotationAge <= 0)
1450 : 0 : return;
1451 : :
1452 : : /*
1453 : : * The requirements here are to choose the next time > now that is a
1454 : : * "multiple" of the log rotation interval. "Multiple" can be interpreted
1455 : : * fairly loosely. In this version we align to log_timezone rather than
1456 : : * GMT.
1457 : : */
1458 : 0 : rotinterval = Log_RotationAge * SECS_PER_MINUTE; /* convert to seconds */
1459 : 0 : now = (pg_time_t) time(NULL);
1460 : 0 : tm = pg_localtime(&now, log_timezone);
1461 : 0 : now += tm->tm_gmtoff;
1462 : 0 : now -= now % rotinterval;
1463 : 0 : now += rotinterval;
1464 : 0 : now -= tm->tm_gmtoff;
1465 : 0 : next_rotation_time = now;
1466 [ # # ]: 0 : }
1467 : :
1468 : : /*
1469 : : * Store the name of the file(s) where the log collector, when enabled, writes
1470 : : * log messages. Useful for finding the name(s) of the current log file(s)
1471 : : * when there is time-based logfile rotation. Filenames are stored in a
1472 : : * temporary file and which is renamed into the final destination for
1473 : : * atomicity. The file is opened with the same permissions as what gets
1474 : : * created in the data directory and has proper buffering options.
1475 : : */
1476 : : static void
1477 : 0 : update_metainfo_datafile(void)
1478 : : {
1479 : 0 : FILE *fh;
1480 : 0 : mode_t oumask;
1481 : :
1482 [ # # ]: 0 : if (!(Log_destination & LOG_DESTINATION_STDERR) &&
1483 [ # # # # ]: 0 : !(Log_destination & LOG_DESTINATION_CSVLOG) &&
1484 : 0 : !(Log_destination & LOG_DESTINATION_JSONLOG))
1485 : : {
1486 [ # # # # ]: 0 : if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
1487 [ # # # # ]: 0 : ereport(LOG,
1488 : : (errcode_for_file_access(),
1489 : : errmsg("could not remove file \"%s\": %m",
1490 : : LOG_METAINFO_DATAFILE)));
1491 : 0 : return;
1492 : : }
1493 : :
1494 : : /* use the same permissions as the data directory for the new file */
1495 : 0 : oumask = umask(pg_mode_mask);
1496 : 0 : fh = fopen(LOG_METAINFO_DATAFILE_TMP, "w");
1497 : 0 : umask(oumask);
1498 : :
1499 [ # # ]: 0 : if (fh)
1500 : : {
1501 : 0 : setvbuf(fh, NULL, PG_IOLBF, 0);
1502 : :
1503 : : #ifdef WIN32
1504 : : /* use CRLF line endings on Windows */
1505 : : _setmode(_fileno(fh), _O_TEXT);
1506 : : #endif
1507 : 0 : }
1508 : : else
1509 : : {
1510 [ # # # # ]: 0 : ereport(LOG,
1511 : : (errcode_for_file_access(),
1512 : : errmsg("could not open file \"%s\": %m",
1513 : : LOG_METAINFO_DATAFILE_TMP)));
1514 : 0 : return;
1515 : : }
1516 : :
1517 [ # # # # ]: 0 : if (last_sys_file_name && (Log_destination & LOG_DESTINATION_STDERR))
1518 : : {
1519 [ # # ]: 0 : if (fprintf(fh, "stderr %s\n", last_sys_file_name) < 0)
1520 : : {
1521 [ # # # # ]: 0 : ereport(LOG,
1522 : : (errcode_for_file_access(),
1523 : : errmsg("could not write file \"%s\": %m",
1524 : : LOG_METAINFO_DATAFILE_TMP)));
1525 : 0 : fclose(fh);
1526 : 0 : return;
1527 : : }
1528 : 0 : }
1529 : :
1530 [ # # # # ]: 0 : if (last_csv_file_name && (Log_destination & LOG_DESTINATION_CSVLOG))
1531 : : {
1532 [ # # ]: 0 : if (fprintf(fh, "csvlog %s\n", last_csv_file_name) < 0)
1533 : : {
1534 [ # # # # ]: 0 : ereport(LOG,
1535 : : (errcode_for_file_access(),
1536 : : errmsg("could not write file \"%s\": %m",
1537 : : LOG_METAINFO_DATAFILE_TMP)));
1538 : 0 : fclose(fh);
1539 : 0 : return;
1540 : : }
1541 : 0 : }
1542 : :
1543 [ # # # # ]: 0 : if (last_json_file_name && (Log_destination & LOG_DESTINATION_JSONLOG))
1544 : : {
1545 [ # # ]: 0 : if (fprintf(fh, "jsonlog %s\n", last_json_file_name) < 0)
1546 : : {
1547 [ # # # # ]: 0 : ereport(LOG,
1548 : : (errcode_for_file_access(),
1549 : : errmsg("could not write file \"%s\": %m",
1550 : : LOG_METAINFO_DATAFILE_TMP)));
1551 : 0 : fclose(fh);
1552 : 0 : return;
1553 : : }
1554 : 0 : }
1555 : 0 : fclose(fh);
1556 : :
1557 [ # # ]: 0 : if (rename(LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE) != 0)
1558 [ # # # # ]: 0 : ereport(LOG,
1559 : : (errcode_for_file_access(),
1560 : : errmsg("could not rename file \"%s\" to \"%s\": %m",
1561 : : LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE)));
1562 [ # # ]: 0 : }
1563 : :
1564 : : /* --------------------------------
1565 : : * signal handler routines
1566 : : * --------------------------------
1567 : : */
1568 : :
1569 : : /*
1570 : : * Check to see if a log rotation request has arrived. Should be
1571 : : * called by postmaster after receiving SIGUSR1.
1572 : : */
1573 : : bool
1574 : 0 : CheckLogrotateSignal(void)
1575 : : {
1576 : 0 : struct stat stat_buf;
1577 : :
1578 [ # # ]: 0 : if (stat(LOGROTATE_SIGNAL_FILE, &stat_buf) == 0)
1579 : 0 : return true;
1580 : :
1581 : 0 : return false;
1582 : 0 : }
1583 : :
1584 : : /*
1585 : : * Remove the file signaling a log rotation request.
1586 : : */
1587 : : void
1588 : 2 : RemoveLogrotateSignalFiles(void)
1589 : : {
1590 : 2 : unlink(LOGROTATE_SIGNAL_FILE);
1591 : 2 : }
1592 : :
1593 : : /* SIGUSR1: set flag to rotate logfile */
1594 : : static void
1595 : 0 : sigUsr1Handler(SIGNAL_ARGS)
1596 : : {
1597 : 0 : rotation_requested = true;
1598 : 0 : SetLatch(MyLatch);
1599 : 0 : }
|
