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