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-2024, 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 2 : SysLoggerMain(char *startup_data, size_t startup_data_len)
166 : {
167 : #ifndef WIN32
168 : char logbuffer[READ_BUF_SIZE];
169 2 : int bytes_in_logbuffer = 0;
170 : #endif
171 : char *currentLogDir;
172 : char *currentLogFilename;
173 : int currentLogRotationAge;
174 : pg_time_t now;
175 : 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 : SysloggerStartupData *slsdata = (SysloggerStartupData *) 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 : 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 2 : if (PostmasterContext)
202 : {
203 2 : MemoryContextDelete(PostmasterContext);
204 2 : PostmasterContext = NULL;
205 : }
206 :
207 2 : now = MyStartTime;
208 :
209 2 : MyBackendType = B_LOGGER;
210 2 : 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 2 : 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 : }
242 : }
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 2 : if (syslogPipe[1] >= 0)
261 2 : close(syslogPipe[1]);
262 2 : 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 2 : pqsignal(SIGHUP, SignalHandlerForConfigReload); /* set flag to read config
278 : * file */
279 2 : pqsignal(SIGINT, SIG_IGN);
280 2 : pqsignal(SIGTERM, SIG_IGN);
281 2 : pqsignal(SIGQUIT, SIG_IGN);
282 2 : pqsignal(SIGALRM, SIG_IGN);
283 2 : pqsignal(SIGPIPE, SIG_IGN);
284 2 : pqsignal(SIGUSR1, sigUsr1Handler); /* request log rotation */
285 2 : pqsignal(SIGUSR2, SIG_IGN);
286 :
287 : /*
288 : * Reset some signals that are accepted by postmaster but not here
289 : */
290 2 : pqsignal(SIGCHLD, SIG_DFL);
291 :
292 2 : 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 2 : last_sys_file_name = logfile_getname(first_syslogger_file_time, NULL);
310 2 : if (csvlogFile != NULL)
311 2 : last_csv_file_name = logfile_getname(first_syslogger_file_time, ".csv");
312 2 : if (jsonlogFile != NULL)
313 2 : last_json_file_name = logfile_getname(first_syslogger_file_time, ".json");
314 :
315 : /* remember active logfile parameters */
316 2 : currentLogDir = pstrdup(Log_directory);
317 2 : currentLogFilename = pstrdup(Log_filename);
318 2 : currentLogRotationAge = Log_RotationAge;
319 : /* set next planned rotation time */
320 2 : set_next_rotation_time();
321 2 : 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 2 : 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 2 : wes = CreateWaitEventSet(NULL, 2);
341 2 : AddWaitEventToSet(wes, WL_LATCH_SET, PGINVALID_SOCKET, MyLatch, NULL);
342 : #ifndef WIN32
343 2 : AddWaitEventToSet(wes, WL_SOCKET_READABLE, syslogPipe[0], NULL, NULL);
344 : #endif
345 :
346 : /* main worker loop */
347 : for (;;)
348 70 : {
349 72 : bool time_based_rotation = false;
350 72 : int size_rotation_for = 0;
351 : long cur_timeout;
352 : WaitEvent event;
353 :
354 : #ifndef WIN32
355 : int rc;
356 : #endif
357 :
358 : /* Clear any already-pending wakeups */
359 72 : ResetLatch(MyLatch);
360 :
361 : /*
362 : * Process any requests or signals received recently.
363 : */
364 72 : 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 : }
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 : }
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 : (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 : (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 : }
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 : }
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 : }
435 :
436 72 : 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 : }
443 :
444 72 : if (!rotation_requested && Log_RotationSize > 0 && !rotation_disabled)
445 : {
446 : /* Do a rotation if file is too big */
447 70 : if (ftell(syslogFile) >= Log_RotationSize * 1024L)
448 : {
449 0 : rotation_requested = true;
450 0 : size_rotation_for |= LOG_DESTINATION_STDERR;
451 : }
452 70 : if (csvlogFile != NULL &&
453 70 : ftell(csvlogFile) >= Log_RotationSize * 1024L)
454 : {
455 0 : rotation_requested = true;
456 0 : size_rotation_for |= LOG_DESTINATION_CSVLOG;
457 : }
458 70 : if (jsonlogFile != NULL &&
459 70 : ftell(jsonlogFile) >= Log_RotationSize * 1024L)
460 : {
461 0 : rotation_requested = true;
462 0 : size_rotation_for |= LOG_DESTINATION_JSONLOG;
463 : }
464 : }
465 :
466 72 : 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 2 : if (!time_based_rotation && size_rotation_for == 0)
473 2 : size_rotation_for = LOG_DESTINATION_STDERR |
474 : LOG_DESTINATION_CSVLOG |
475 : LOG_DESTINATION_JSONLOG;
476 2 : logfile_rotate(time_based_rotation, size_rotation_for);
477 : }
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 72 : if (Log_RotationAge > 0 && !rotation_disabled)
492 0 : {
493 : 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 : }
502 : else
503 0 : cur_timeout = 0;
504 : }
505 : else
506 72 : cur_timeout = -1L;
507 :
508 : /*
509 : * Sleep until there's something to do
510 : */
511 : #ifndef WIN32
512 72 : rc = WaitEventSetWait(wes, cur_timeout, &event, 1,
513 : WAIT_EVENT_SYSLOGGER_MAIN);
514 :
515 72 : if (rc == 1 && event.events == WL_SOCKET_READABLE)
516 : {
517 : int bytesRead;
518 :
519 70 : bytesRead = read(syslogPipe[0],
520 : logbuffer + bytes_in_logbuffer,
521 : sizeof(logbuffer) - bytes_in_logbuffer);
522 70 : 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 : }
529 70 : else if (bytesRead > 0)
530 : {
531 68 : bytes_in_logbuffer += bytesRead;
532 68 : process_pipe_input(logbuffer, &bytes_in_logbuffer);
533 68 : 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 2 : pipe_eof_seen = true;
544 :
545 : /* if there's any data left then force it out now */
546 2 : flush_pipe_input(logbuffer, &bytes_in_logbuffer);
547 : }
548 : }
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 4 : 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 2 : 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 2 : proc_exit(0);
585 : }
586 : }
587 : }
588 :
589 : /*
590 : * Postmaster subroutine to start a syslogger subprocess.
591 : */
592 : int
593 1444 : SysLogger_Start(void)
594 : {
595 : pid_t sysloggerPid;
596 : char *filename;
597 : #ifdef EXEC_BACKEND
598 : SysloggerStartupData startup_data;
599 : #endif /* EXEC_BACKEND */
600 :
601 1444 : if (!Logging_collector)
602 1442 : return 0;
603 :
604 : /*
605 : * If first time through, create the pipe which will receive stderr
606 : * output.
607 : *
608 : * If the syslogger crashes and needs to be restarted, we continue to use
609 : * the same pipe (indeed must do so, since extant backends will be writing
610 : * into that pipe).
611 : *
612 : * This means the postmaster must continue to hold the read end of the
613 : * pipe open, so we can pass it down to the reincarnated syslogger. This
614 : * is a bit klugy but we have little choice.
615 : *
616 : * Also note that we don't bother counting the pipe FDs by calling
617 : * Reserve/ReleaseExternalFD. There's no real need to account for them
618 : * accurately in the postmaster or syslogger process, and both ends of the
619 : * pipe will wind up closed in all other postmaster children.
620 : */
621 : #ifndef WIN32
622 2 : if (syslogPipe[0] < 0)
623 : {
624 2 : if (pipe(syslogPipe) < 0)
625 0 : ereport(FATAL,
626 : (errcode_for_socket_access(),
627 : errmsg("could not create pipe for syslog: %m")));
628 : }
629 : #else
630 : if (!syslogPipe[0])
631 : {
632 : SECURITY_ATTRIBUTES sa;
633 :
634 : memset(&sa, 0, sizeof(SECURITY_ATTRIBUTES));
635 : sa.nLength = sizeof(SECURITY_ATTRIBUTES);
636 : sa.bInheritHandle = TRUE;
637 :
638 : if (!CreatePipe(&syslogPipe[0], &syslogPipe[1], &sa, 32768))
639 : ereport(FATAL,
640 : (errcode_for_file_access(),
641 : errmsg("could not create pipe for syslog: %m")));
642 : }
643 : #endif
644 :
645 : /*
646 : * Create log directory if not present; ignore errors
647 : */
648 2 : (void) MakePGDirectory(Log_directory);
649 :
650 : /*
651 : * The initial logfile is created right in the postmaster, to verify that
652 : * the Log_directory is writable. We save the reference time so that the
653 : * syslogger child process can recompute this file name.
654 : *
655 : * It might look a bit strange to re-do this during a syslogger restart,
656 : * but we must do so since the postmaster closed syslogFile after the
657 : * previous fork (and remembering that old file wouldn't be right anyway).
658 : * Note we always append here, we won't overwrite any existing file. This
659 : * is consistent with the normal rules, because by definition this is not
660 : * a time-based rotation.
661 : */
662 2 : first_syslogger_file_time = time(NULL);
663 :
664 2 : filename = logfile_getname(first_syslogger_file_time, NULL);
665 :
666 2 : syslogFile = logfile_open(filename, "a", false);
667 :
668 2 : pfree(filename);
669 :
670 : /*
671 : * Likewise for the initial CSV log file, if that's enabled. (Note that
672 : * we open syslogFile even when only CSV output is nominally enabled,
673 : * since some code paths will write to syslogFile anyway.)
674 : */
675 2 : if (Log_destination & LOG_DESTINATION_CSVLOG)
676 : {
677 2 : filename = logfile_getname(first_syslogger_file_time, ".csv");
678 :
679 2 : csvlogFile = logfile_open(filename, "a", false);
680 :
681 2 : pfree(filename);
682 : }
683 :
684 : /*
685 : * Likewise for the initial JSON log file, if that's enabled. (Note that
686 : * we open syslogFile even when only JSON output is nominally enabled,
687 : * since some code paths will write to syslogFile anyway.)
688 : */
689 2 : if (Log_destination & LOG_DESTINATION_JSONLOG)
690 : {
691 2 : filename = logfile_getname(first_syslogger_file_time, ".json");
692 :
693 2 : jsonlogFile = logfile_open(filename, "a", false);
694 :
695 2 : pfree(filename);
696 : }
697 :
698 : #ifdef EXEC_BACKEND
699 : startup_data.syslogFile = syslogger_fdget(syslogFile);
700 : startup_data.csvlogFile = syslogger_fdget(csvlogFile);
701 : startup_data.jsonlogFile = syslogger_fdget(jsonlogFile);
702 : sysloggerPid = postmaster_child_launch(B_LOGGER, (char *) &startup_data, sizeof(startup_data), NULL);
703 : #else
704 2 : sysloggerPid = postmaster_child_launch(B_LOGGER, NULL, 0, NULL);
705 : #endif /* EXEC_BACKEND */
706 :
707 2 : if (sysloggerPid == -1)
708 : {
709 0 : ereport(LOG,
710 : (errmsg("could not fork system logger: %m")));
711 0 : return 0;
712 : }
713 :
714 : /* success, in postmaster */
715 :
716 : /* now we redirect stderr, if not done already */
717 2 : if (!redirection_done)
718 : {
719 : #ifdef WIN32
720 : int fd;
721 : #endif
722 :
723 : /*
724 : * Leave a breadcrumb trail when redirecting, in case the user forgets
725 : * that redirection is active and looks only at the original stderr
726 : * target file.
727 : */
728 2 : ereport(LOG,
729 : (errmsg("redirecting log output to logging collector process"),
730 : errhint("Future log output will appear in directory \"%s\".",
731 : Log_directory)));
732 :
733 : #ifndef WIN32
734 2 : fflush(stdout);
735 2 : if (dup2(syslogPipe[1], STDOUT_FILENO) < 0)
736 0 : ereport(FATAL,
737 : (errcode_for_file_access(),
738 : errmsg("could not redirect stdout: %m")));
739 2 : fflush(stderr);
740 2 : if (dup2(syslogPipe[1], STDERR_FILENO) < 0)
741 0 : ereport(FATAL,
742 : (errcode_for_file_access(),
743 : errmsg("could not redirect stderr: %m")));
744 : /* Now we are done with the write end of the pipe. */
745 2 : close(syslogPipe[1]);
746 2 : syslogPipe[1] = -1;
747 : #else
748 :
749 : /*
750 : * open the pipe in binary mode and make sure stderr is binary after
751 : * it's been dup'ed into, to avoid disturbing the pipe chunking
752 : * protocol.
753 : */
754 : fflush(stderr);
755 : fd = _open_osfhandle((intptr_t) syslogPipe[1],
756 : _O_APPEND | _O_BINARY);
757 : if (dup2(fd, STDERR_FILENO) < 0)
758 : ereport(FATAL,
759 : (errcode_for_file_access(),
760 : errmsg("could not redirect stderr: %m")));
761 : close(fd);
762 : _setmode(STDERR_FILENO, _O_BINARY);
763 :
764 : /*
765 : * Now we are done with the write end of the pipe. CloseHandle() must
766 : * not be called because the preceding close() closes the underlying
767 : * handle.
768 : */
769 : syslogPipe[1] = 0;
770 : #endif
771 2 : redirection_done = true;
772 : }
773 :
774 : /* postmaster will never write the file(s); close 'em */
775 2 : fclose(syslogFile);
776 2 : syslogFile = NULL;
777 2 : if (csvlogFile != NULL)
778 : {
779 2 : fclose(csvlogFile);
780 2 : csvlogFile = NULL;
781 : }
782 2 : if (jsonlogFile != NULL)
783 : {
784 2 : fclose(jsonlogFile);
785 2 : jsonlogFile = NULL;
786 : }
787 2 : return (int) sysloggerPid;
788 : }
789 :
790 :
791 : #ifdef EXEC_BACKEND
792 :
793 : /*
794 : * syslogger_fdget() -
795 : *
796 : * Utility wrapper to grab the file descriptor of an opened error output
797 : * file. Used when building the command to fork the logging collector.
798 : */
799 : static int
800 : syslogger_fdget(FILE *file)
801 : {
802 : #ifndef WIN32
803 : if (file != NULL)
804 : return fileno(file);
805 : else
806 : return -1;
807 : #else
808 : if (file != NULL)
809 : return (int) _get_osfhandle(_fileno(file));
810 : else
811 : return 0;
812 : #endif /* WIN32 */
813 : }
814 :
815 : /*
816 : * syslogger_fdopen() -
817 : *
818 : * Utility wrapper to re-open an error output file, using the given file
819 : * descriptor. Used when parsing arguments in a forked logging collector.
820 : */
821 : static FILE *
822 : syslogger_fdopen(int fd)
823 : {
824 : FILE *file = NULL;
825 :
826 : #ifndef WIN32
827 : if (fd != -1)
828 : {
829 : file = fdopen(fd, "a");
830 : setvbuf(file, NULL, PG_IOLBF, 0);
831 : }
832 : #else /* WIN32 */
833 : if (fd != 0)
834 : {
835 : fd = _open_osfhandle(fd, _O_APPEND | _O_TEXT);
836 : if (fd > 0)
837 : {
838 : file = fdopen(fd, "a");
839 : setvbuf(file, NULL, PG_IOLBF, 0);
840 : }
841 : }
842 : #endif /* WIN32 */
843 :
844 : return file;
845 : }
846 : #endif /* EXEC_BACKEND */
847 :
848 :
849 : /* --------------------------------
850 : * pipe protocol handling
851 : * --------------------------------
852 : */
853 :
854 : /*
855 : * Process data received through the syslogger pipe.
856 : *
857 : * This routine interprets the log pipe protocol which sends log messages as
858 : * (hopefully atomic) chunks - such chunks are detected and reassembled here.
859 : *
860 : * The protocol has a header that starts with two nul bytes, then has a 16 bit
861 : * length, the pid of the sending process, and a flag to indicate if it is
862 : * the last chunk in a message. Incomplete chunks are saved until we read some
863 : * more, and non-final chunks are accumulated until we get the final chunk.
864 : *
865 : * All of this is to avoid 2 problems:
866 : * . partial messages being written to logfiles (messes rotation), and
867 : * . messages from different backends being interleaved (messages garbled).
868 : *
869 : * Any non-protocol messages are written out directly. These should only come
870 : * from non-PostgreSQL sources, however (e.g. third party libraries writing to
871 : * stderr).
872 : *
873 : * logbuffer is the data input buffer, and *bytes_in_logbuffer is the number
874 : * of bytes present. On exit, any not-yet-eaten data is left-justified in
875 : * logbuffer, and *bytes_in_logbuffer is updated.
876 : */
877 : static void
878 68 : process_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
879 : {
880 68 : char *cursor = logbuffer;
881 68 : int count = *bytes_in_logbuffer;
882 68 : int dest = LOG_DESTINATION_STDERR;
883 :
884 : /* While we have enough for a header, process data... */
885 188 : while (count >= (int) (offsetof(PipeProtoHeader, data) + 1))
886 : {
887 : PipeProtoHeader p;
888 : int chunklen;
889 : bits8 dest_flags;
890 :
891 : /* Do we have a valid header? */
892 120 : memcpy(&p, cursor, offsetof(PipeProtoHeader, data));
893 120 : dest_flags = p.flags & (PIPE_PROTO_DEST_STDERR |
894 : PIPE_PROTO_DEST_CSVLOG |
895 : PIPE_PROTO_DEST_JSONLOG);
896 120 : if (p.nuls[0] == '\0' && p.nuls[1] == '\0' &&
897 120 : p.len > 0 && p.len <= PIPE_MAX_PAYLOAD &&
898 120 : p.pid != 0 &&
899 120 : pg_number_of_ones[dest_flags] == 1)
900 120 : {
901 : List *buffer_list;
902 : ListCell *cell;
903 120 : save_buffer *existing_slot = NULL,
904 120 : *free_slot = NULL;
905 : StringInfo str;
906 :
907 120 : chunklen = PIPE_HEADER_SIZE + p.len;
908 :
909 : /* Fall out of loop if we don't have the whole chunk yet */
910 120 : if (count < chunklen)
911 0 : break;
912 :
913 120 : if ((p.flags & PIPE_PROTO_DEST_STDERR) != 0)
914 40 : dest = LOG_DESTINATION_STDERR;
915 80 : else if ((p.flags & PIPE_PROTO_DEST_CSVLOG) != 0)
916 40 : dest = LOG_DESTINATION_CSVLOG;
917 40 : else if ((p.flags & PIPE_PROTO_DEST_JSONLOG) != 0)
918 40 : dest = LOG_DESTINATION_JSONLOG;
919 : else
920 : {
921 : /* this should never happen as of the header validation */
922 : Assert(false);
923 : }
924 :
925 : /* Locate any existing buffer for this source pid */
926 120 : buffer_list = buffer_lists[p.pid % NBUFFER_LISTS];
927 120 : foreach(cell, buffer_list)
928 : {
929 0 : save_buffer *buf = (save_buffer *) lfirst(cell);
930 :
931 0 : if (buf->pid == p.pid)
932 : {
933 0 : existing_slot = buf;
934 0 : break;
935 : }
936 0 : if (buf->pid == 0 && free_slot == NULL)
937 0 : free_slot = buf;
938 : }
939 :
940 120 : if ((p.flags & PIPE_PROTO_IS_LAST) == 0)
941 : {
942 : /*
943 : * Save a complete non-final chunk in a per-pid buffer
944 : */
945 0 : if (existing_slot != NULL)
946 : {
947 : /* Add chunk to data from preceding chunks */
948 0 : str = &(existing_slot->data);
949 0 : appendBinaryStringInfo(str,
950 0 : cursor + PIPE_HEADER_SIZE,
951 0 : p.len);
952 : }
953 : else
954 : {
955 : /* First chunk of message, save in a new buffer */
956 0 : if (free_slot == NULL)
957 : {
958 : /*
959 : * Need a free slot, but there isn't one in the list,
960 : * so create a new one and extend the list with it.
961 : */
962 0 : free_slot = palloc(sizeof(save_buffer));
963 0 : buffer_list = lappend(buffer_list, free_slot);
964 0 : buffer_lists[p.pid % NBUFFER_LISTS] = buffer_list;
965 : }
966 0 : free_slot->pid = p.pid;
967 0 : str = &(free_slot->data);
968 0 : initStringInfo(str);
969 0 : appendBinaryStringInfo(str,
970 0 : cursor + PIPE_HEADER_SIZE,
971 0 : p.len);
972 : }
973 : }
974 : else
975 : {
976 : /*
977 : * Final chunk --- add it to anything saved for that pid, and
978 : * either way write the whole thing out.
979 : */
980 120 : if (existing_slot != NULL)
981 : {
982 0 : str = &(existing_slot->data);
983 0 : appendBinaryStringInfo(str,
984 0 : cursor + PIPE_HEADER_SIZE,
985 0 : p.len);
986 0 : write_syslogger_file(str->data, str->len, dest);
987 : /* Mark the buffer unused, and reclaim string storage */
988 0 : existing_slot->pid = 0;
989 0 : pfree(str->data);
990 : }
991 : else
992 : {
993 : /* The whole message was one chunk, evidently. */
994 120 : write_syslogger_file(cursor + PIPE_HEADER_SIZE, p.len,
995 : dest);
996 : }
997 : }
998 :
999 : /* Finished processing this chunk */
1000 120 : cursor += chunklen;
1001 120 : count -= chunklen;
1002 : }
1003 : else
1004 : {
1005 : /* Process non-protocol data */
1006 :
1007 : /*
1008 : * Look for the start of a protocol header. If found, dump data
1009 : * up to there and repeat the loop. Otherwise, dump it all and
1010 : * fall out of the loop. (Note: we want to dump it all if at all
1011 : * possible, so as to avoid dividing non-protocol messages across
1012 : * logfiles. We expect that in many scenarios, a non-protocol
1013 : * message will arrive all in one read(), and we want to respect
1014 : * the read() boundary if possible.)
1015 : */
1016 0 : for (chunklen = 1; chunklen < count; chunklen++)
1017 : {
1018 0 : if (cursor[chunklen] == '\0')
1019 0 : break;
1020 : }
1021 : /* fall back on the stderr log as the destination */
1022 0 : write_syslogger_file(cursor, chunklen, LOG_DESTINATION_STDERR);
1023 0 : cursor += chunklen;
1024 0 : count -= chunklen;
1025 : }
1026 : }
1027 :
1028 : /* We don't have a full chunk, so left-align what remains in the buffer */
1029 68 : if (count > 0 && cursor != logbuffer)
1030 0 : memmove(logbuffer, cursor, count);
1031 68 : *bytes_in_logbuffer = count;
1032 68 : }
1033 :
1034 : /*
1035 : * Force out any buffered data
1036 : *
1037 : * This is currently used only at syslogger shutdown, but could perhaps be
1038 : * useful at other times, so it is careful to leave things in a clean state.
1039 : */
1040 : static void
1041 2 : flush_pipe_input(char *logbuffer, int *bytes_in_logbuffer)
1042 : {
1043 : int i;
1044 :
1045 : /* Dump any incomplete protocol messages */
1046 514 : for (i = 0; i < NBUFFER_LISTS; i++)
1047 : {
1048 512 : List *list = buffer_lists[i];
1049 : ListCell *cell;
1050 :
1051 512 : foreach(cell, list)
1052 : {
1053 0 : save_buffer *buf = (save_buffer *) lfirst(cell);
1054 :
1055 0 : if (buf->pid != 0)
1056 : {
1057 0 : StringInfo str = &(buf->data);
1058 :
1059 0 : write_syslogger_file(str->data, str->len,
1060 : LOG_DESTINATION_STDERR);
1061 : /* Mark the buffer unused, and reclaim string storage */
1062 0 : buf->pid = 0;
1063 0 : pfree(str->data);
1064 : }
1065 : }
1066 : }
1067 :
1068 : /*
1069 : * Force out any remaining pipe data as-is; we don't bother trying to
1070 : * remove any protocol headers that may exist in it.
1071 : */
1072 2 : if (*bytes_in_logbuffer > 0)
1073 0 : write_syslogger_file(logbuffer, *bytes_in_logbuffer,
1074 : LOG_DESTINATION_STDERR);
1075 2 : *bytes_in_logbuffer = 0;
1076 2 : }
1077 :
1078 :
1079 : /* --------------------------------
1080 : * logfile routines
1081 : * --------------------------------
1082 : */
1083 :
1084 : /*
1085 : * Write text to the currently open logfile
1086 : *
1087 : * This is exported so that elog.c can call it when MyBackendType is B_LOGGER.
1088 : * This allows the syslogger process to record elog messages of its own,
1089 : * even though its stderr does not point at the syslog pipe.
1090 : */
1091 : void
1092 120 : write_syslogger_file(const char *buffer, int count, int destination)
1093 : {
1094 : int rc;
1095 : FILE *logfile;
1096 :
1097 : /*
1098 : * If we're told to write to a structured log file, but it's not open,
1099 : * dump the data to syslogFile (which is always open) instead. This can
1100 : * happen if structured output is enabled after postmaster start and we've
1101 : * been unable to open logFile. There are also race conditions during a
1102 : * parameter change whereby backends might send us structured output
1103 : * before we open the logFile or after we close it. Writing formatted
1104 : * output to the regular log file isn't great, but it beats dropping log
1105 : * output on the floor.
1106 : *
1107 : * Think not to improve this by trying to open logFile on-the-fly. Any
1108 : * failure in that would lead to recursion.
1109 : */
1110 120 : if ((destination & LOG_DESTINATION_CSVLOG) && csvlogFile != NULL)
1111 40 : logfile = csvlogFile;
1112 80 : else if ((destination & LOG_DESTINATION_JSONLOG) && jsonlogFile != NULL)
1113 40 : logfile = jsonlogFile;
1114 : else
1115 40 : logfile = syslogFile;
1116 :
1117 120 : rc = fwrite(buffer, 1, count, logfile);
1118 :
1119 : /*
1120 : * Try to report any failure. We mustn't use ereport because it would
1121 : * just recurse right back here, but write_stderr is OK: it will write
1122 : * either to the postmaster's original stderr, or to /dev/null, but never
1123 : * to our input pipe which would result in a different sort of looping.
1124 : */
1125 120 : if (rc != count)
1126 0 : write_stderr("could not write to log file: %m\n");
1127 120 : }
1128 :
1129 : #ifdef WIN32
1130 :
1131 : /*
1132 : * Worker thread to transfer data from the pipe to the current logfile.
1133 : *
1134 : * We need this because on Windows, WaitForMultipleObjects does not work on
1135 : * unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
1136 : * allow for SIGHUP; and select is for sockets only.
1137 : */
1138 : static unsigned int __stdcall
1139 : pipeThread(void *arg)
1140 : {
1141 : char logbuffer[READ_BUF_SIZE];
1142 : int bytes_in_logbuffer = 0;
1143 :
1144 : for (;;)
1145 : {
1146 : DWORD bytesRead;
1147 : BOOL result;
1148 :
1149 : result = ReadFile(syslogPipe[0],
1150 : logbuffer + bytes_in_logbuffer,
1151 : sizeof(logbuffer) - bytes_in_logbuffer,
1152 : &bytesRead, 0);
1153 :
1154 : /*
1155 : * Enter critical section before doing anything that might touch
1156 : * global state shared by the main thread. Anything that uses
1157 : * palloc()/pfree() in particular are not safe outside the critical
1158 : * section.
1159 : */
1160 : EnterCriticalSection(&sysloggerSection);
1161 : if (!result)
1162 : {
1163 : DWORD error = GetLastError();
1164 :
1165 : if (error == ERROR_HANDLE_EOF ||
1166 : error == ERROR_BROKEN_PIPE)
1167 : break;
1168 : _dosmaperr(error);
1169 : ereport(LOG,
1170 : (errcode_for_file_access(),
1171 : errmsg("could not read from logger pipe: %m")));
1172 : }
1173 : else if (bytesRead > 0)
1174 : {
1175 : bytes_in_logbuffer += bytesRead;
1176 : process_pipe_input(logbuffer, &bytes_in_logbuffer);
1177 : }
1178 :
1179 : /*
1180 : * If we've filled the current logfile, nudge the main thread to do a
1181 : * log rotation.
1182 : */
1183 : if (Log_RotationSize > 0)
1184 : {
1185 : if (ftell(syslogFile) >= Log_RotationSize * 1024L ||
1186 : (csvlogFile != NULL && ftell(csvlogFile) >= Log_RotationSize * 1024L) ||
1187 : (jsonlogFile != NULL && ftell(jsonlogFile) >= Log_RotationSize * 1024L))
1188 : SetLatch(MyLatch);
1189 : }
1190 : LeaveCriticalSection(&sysloggerSection);
1191 : }
1192 :
1193 : /* We exit the above loop only upon detecting pipe EOF */
1194 : pipe_eof_seen = true;
1195 :
1196 : /* if there's any data left then force it out now */
1197 : flush_pipe_input(logbuffer, &bytes_in_logbuffer);
1198 :
1199 : /* set the latch to waken the main thread, which will quit */
1200 : SetLatch(MyLatch);
1201 :
1202 : LeaveCriticalSection(&sysloggerSection);
1203 : _endthread();
1204 : return 0;
1205 : }
1206 : #endif /* WIN32 */
1207 :
1208 : /*
1209 : * Open a new logfile with proper permissions and buffering options.
1210 : *
1211 : * If allow_errors is true, we just log any open failure and return NULL
1212 : * (with errno still correct for the fopen failure).
1213 : * Otherwise, errors are treated as fatal.
1214 : */
1215 : static FILE *
1216 12 : logfile_open(const char *filename, const char *mode, bool allow_errors)
1217 : {
1218 : FILE *fh;
1219 : mode_t oumask;
1220 :
1221 : /*
1222 : * Note we do not let Log_file_mode disable IWUSR, since we certainly want
1223 : * to be able to write the files ourselves.
1224 : */
1225 12 : oumask = umask((mode_t) ((~(Log_file_mode | S_IWUSR)) & (S_IRWXU | S_IRWXG | S_IRWXO)));
1226 12 : fh = fopen(filename, mode);
1227 12 : umask(oumask);
1228 :
1229 12 : if (fh)
1230 : {
1231 12 : setvbuf(fh, NULL, PG_IOLBF, 0);
1232 :
1233 : #ifdef WIN32
1234 : /* use CRLF line endings on Windows */
1235 : _setmode(_fileno(fh), _O_TEXT);
1236 : #endif
1237 : }
1238 : else
1239 : {
1240 0 : int save_errno = errno;
1241 :
1242 0 : ereport(allow_errors ? LOG : FATAL,
1243 : (errcode_for_file_access(),
1244 : errmsg("could not open log file \"%s\": %m",
1245 : filename)));
1246 0 : errno = save_errno;
1247 : }
1248 :
1249 12 : return fh;
1250 : }
1251 :
1252 : /*
1253 : * Do logfile rotation for a single destination, as specified by target_dest.
1254 : * The information stored in *last_file_name and *logFile is updated on a
1255 : * successful file rotation.
1256 : *
1257 : * Returns false if the rotation has been stopped, or true to move on to
1258 : * the processing of other formats.
1259 : */
1260 : static bool
1261 6 : logfile_rotate_dest(bool time_based_rotation, int size_rotation_for,
1262 : pg_time_t fntime, int target_dest,
1263 : char **last_file_name, FILE **logFile)
1264 : {
1265 6 : char *logFileExt = NULL;
1266 : char *filename;
1267 : FILE *fh;
1268 :
1269 : /*
1270 : * If the target destination was just turned off, close the previous file
1271 : * and unregister its data. This cannot happen for stderr as syslogFile
1272 : * is assumed to be always opened even if stderr is disabled in
1273 : * log_destination.
1274 : */
1275 6 : if ((Log_destination & target_dest) == 0 &&
1276 : target_dest != LOG_DESTINATION_STDERR)
1277 : {
1278 0 : if (*logFile != NULL)
1279 0 : fclose(*logFile);
1280 0 : *logFile = NULL;
1281 0 : if (*last_file_name != NULL)
1282 0 : pfree(*last_file_name);
1283 0 : *last_file_name = NULL;
1284 0 : return true;
1285 : }
1286 :
1287 : /*
1288 : * Leave if it is not time for a rotation or if the target destination has
1289 : * no need to do a rotation based on the size of its file.
1290 : */
1291 6 : if (!time_based_rotation && (size_rotation_for & target_dest) == 0)
1292 0 : return true;
1293 :
1294 : /* file extension depends on the destination type */
1295 6 : if (target_dest == LOG_DESTINATION_STDERR)
1296 2 : logFileExt = NULL;
1297 4 : else if (target_dest == LOG_DESTINATION_CSVLOG)
1298 2 : logFileExt = ".csv";
1299 2 : else if (target_dest == LOG_DESTINATION_JSONLOG)
1300 2 : logFileExt = ".json";
1301 : else
1302 : {
1303 : /* cannot happen */
1304 : Assert(false);
1305 : }
1306 :
1307 : /* build the new file name */
1308 6 : filename = logfile_getname(fntime, logFileExt);
1309 :
1310 : /*
1311 : * Decide whether to overwrite or append. We can overwrite if (a)
1312 : * Log_truncate_on_rotation is set, (b) the rotation was triggered by
1313 : * elapsed time and not something else, and (c) the computed file name is
1314 : * different from what we were previously logging into.
1315 : */
1316 6 : if (Log_truncate_on_rotation && time_based_rotation &&
1317 0 : *last_file_name != NULL &&
1318 0 : strcmp(filename, *last_file_name) != 0)
1319 0 : fh = logfile_open(filename, "w", true);
1320 : else
1321 6 : fh = logfile_open(filename, "a", true);
1322 :
1323 6 : if (!fh)
1324 : {
1325 : /*
1326 : * ENFILE/EMFILE are not too surprising on a busy system; just keep
1327 : * using the old file till we manage to get a new one. Otherwise,
1328 : * assume something's wrong with Log_directory and stop trying to
1329 : * create files.
1330 : */
1331 0 : if (errno != ENFILE && errno != EMFILE)
1332 : {
1333 0 : ereport(LOG,
1334 : (errmsg("disabling automatic rotation (use SIGHUP to re-enable)")));
1335 0 : rotation_disabled = true;
1336 : }
1337 :
1338 0 : if (filename)
1339 0 : pfree(filename);
1340 0 : return false;
1341 : }
1342 :
1343 : /* fill in the new information */
1344 6 : if (*logFile != NULL)
1345 6 : fclose(*logFile);
1346 6 : *logFile = fh;
1347 :
1348 : /* instead of pfree'ing filename, remember it for next time */
1349 6 : if (*last_file_name != NULL)
1350 6 : pfree(*last_file_name);
1351 6 : *last_file_name = filename;
1352 :
1353 6 : return true;
1354 : }
1355 :
1356 : /*
1357 : * perform logfile rotation
1358 : */
1359 : static void
1360 2 : logfile_rotate(bool time_based_rotation, int size_rotation_for)
1361 : {
1362 : pg_time_t fntime;
1363 :
1364 2 : rotation_requested = false;
1365 :
1366 : /*
1367 : * When doing a time-based rotation, invent the new logfile name based on
1368 : * the planned rotation time, not current time, to avoid "slippage" in the
1369 : * file name when we don't do the rotation immediately.
1370 : */
1371 2 : if (time_based_rotation)
1372 0 : fntime = next_rotation_time;
1373 : else
1374 2 : fntime = time(NULL);
1375 :
1376 : /* file rotation for stderr */
1377 2 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1378 : LOG_DESTINATION_STDERR, &last_sys_file_name,
1379 : &syslogFile))
1380 0 : return;
1381 :
1382 : /* file rotation for csvlog */
1383 2 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1384 : LOG_DESTINATION_CSVLOG, &last_csv_file_name,
1385 : &csvlogFile))
1386 0 : return;
1387 :
1388 : /* file rotation for jsonlog */
1389 2 : if (!logfile_rotate_dest(time_based_rotation, size_rotation_for, fntime,
1390 : LOG_DESTINATION_JSONLOG, &last_json_file_name,
1391 : &jsonlogFile))
1392 0 : return;
1393 :
1394 2 : update_metainfo_datafile();
1395 :
1396 2 : set_next_rotation_time();
1397 : }
1398 :
1399 :
1400 : /*
1401 : * construct logfile name using timestamp information
1402 : *
1403 : * If suffix isn't NULL, append it to the name, replacing any ".log"
1404 : * that may be in the pattern.
1405 : *
1406 : * Result is palloc'd.
1407 : */
1408 : static char *
1409 18 : logfile_getname(pg_time_t timestamp, const char *suffix)
1410 : {
1411 : char *filename;
1412 : int len;
1413 :
1414 18 : filename = palloc(MAXPGPATH);
1415 :
1416 18 : snprintf(filename, MAXPGPATH, "%s/", Log_directory);
1417 :
1418 18 : len = strlen(filename);
1419 :
1420 : /* treat Log_filename as a strftime pattern */
1421 18 : pg_strftime(filename + len, MAXPGPATH - len, Log_filename,
1422 18 : pg_localtime(×tamp, log_timezone));
1423 :
1424 18 : if (suffix != NULL)
1425 : {
1426 12 : len = strlen(filename);
1427 12 : if (len > 4 && (strcmp(filename + (len - 4), ".log") == 0))
1428 12 : len -= 4;
1429 12 : strlcpy(filename + len, suffix, MAXPGPATH - len);
1430 : }
1431 :
1432 18 : return filename;
1433 : }
1434 :
1435 : /*
1436 : * Determine the next planned rotation time, and store in next_rotation_time.
1437 : */
1438 : static void
1439 4 : set_next_rotation_time(void)
1440 : {
1441 : pg_time_t now;
1442 : struct pg_tm *tm;
1443 : int rotinterval;
1444 :
1445 : /* nothing to do if time-based rotation is disabled */
1446 4 : if (Log_RotationAge <= 0)
1447 4 : return;
1448 :
1449 : /*
1450 : * The requirements here are to choose the next time > now that is a
1451 : * "multiple" of the log rotation interval. "Multiple" can be interpreted
1452 : * fairly loosely. In this version we align to log_timezone rather than
1453 : * GMT.
1454 : */
1455 0 : rotinterval = Log_RotationAge * SECS_PER_MINUTE; /* convert to seconds */
1456 0 : now = (pg_time_t) time(NULL);
1457 0 : tm = pg_localtime(&now, log_timezone);
1458 0 : now += tm->tm_gmtoff;
1459 0 : now -= now % rotinterval;
1460 0 : now += rotinterval;
1461 0 : now -= tm->tm_gmtoff;
1462 0 : next_rotation_time = now;
1463 : }
1464 :
1465 : /*
1466 : * Store the name of the file(s) where the log collector, when enabled, writes
1467 : * log messages. Useful for finding the name(s) of the current log file(s)
1468 : * when there is time-based logfile rotation. Filenames are stored in a
1469 : * temporary file and which is renamed into the final destination for
1470 : * atomicity. The file is opened with the same permissions as what gets
1471 : * created in the data directory and has proper buffering options.
1472 : */
1473 : static void
1474 4 : update_metainfo_datafile(void)
1475 : {
1476 : FILE *fh;
1477 : mode_t oumask;
1478 :
1479 4 : if (!(Log_destination & LOG_DESTINATION_STDERR) &&
1480 0 : !(Log_destination & LOG_DESTINATION_CSVLOG) &&
1481 0 : !(Log_destination & LOG_DESTINATION_JSONLOG))
1482 : {
1483 0 : if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
1484 0 : ereport(LOG,
1485 : (errcode_for_file_access(),
1486 : errmsg("could not remove file \"%s\": %m",
1487 : LOG_METAINFO_DATAFILE)));
1488 0 : return;
1489 : }
1490 :
1491 : /* use the same permissions as the data directory for the new file */
1492 4 : oumask = umask(pg_mode_mask);
1493 4 : fh = fopen(LOG_METAINFO_DATAFILE_TMP, "w");
1494 4 : umask(oumask);
1495 :
1496 4 : if (fh)
1497 : {
1498 4 : setvbuf(fh, NULL, PG_IOLBF, 0);
1499 :
1500 : #ifdef WIN32
1501 : /* use CRLF line endings on Windows */
1502 : _setmode(_fileno(fh), _O_TEXT);
1503 : #endif
1504 : }
1505 : else
1506 : {
1507 0 : ereport(LOG,
1508 : (errcode_for_file_access(),
1509 : errmsg("could not open file \"%s\": %m",
1510 : LOG_METAINFO_DATAFILE_TMP)));
1511 0 : return;
1512 : }
1513 :
1514 4 : if (last_sys_file_name && (Log_destination & LOG_DESTINATION_STDERR))
1515 : {
1516 4 : if (fprintf(fh, "stderr %s\n", last_sys_file_name) < 0)
1517 : {
1518 0 : ereport(LOG,
1519 : (errcode_for_file_access(),
1520 : errmsg("could not write file \"%s\": %m",
1521 : LOG_METAINFO_DATAFILE_TMP)));
1522 0 : fclose(fh);
1523 0 : return;
1524 : }
1525 : }
1526 :
1527 4 : if (last_csv_file_name && (Log_destination & LOG_DESTINATION_CSVLOG))
1528 : {
1529 4 : if (fprintf(fh, "csvlog %s\n", last_csv_file_name) < 0)
1530 : {
1531 0 : ereport(LOG,
1532 : (errcode_for_file_access(),
1533 : errmsg("could not write file \"%s\": %m",
1534 : LOG_METAINFO_DATAFILE_TMP)));
1535 0 : fclose(fh);
1536 0 : return;
1537 : }
1538 : }
1539 :
1540 4 : if (last_json_file_name && (Log_destination & LOG_DESTINATION_JSONLOG))
1541 : {
1542 4 : if (fprintf(fh, "jsonlog %s\n", last_json_file_name) < 0)
1543 : {
1544 0 : ereport(LOG,
1545 : (errcode_for_file_access(),
1546 : errmsg("could not write file \"%s\": %m",
1547 : LOG_METAINFO_DATAFILE_TMP)));
1548 0 : fclose(fh);
1549 0 : return;
1550 : }
1551 : }
1552 4 : fclose(fh);
1553 :
1554 4 : if (rename(LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE) != 0)
1555 0 : ereport(LOG,
1556 : (errcode_for_file_access(),
1557 : errmsg("could not rename file \"%s\" to \"%s\": %m",
1558 : LOG_METAINFO_DATAFILE_TMP, LOG_METAINFO_DATAFILE)));
1559 : }
1560 :
1561 : /* --------------------------------
1562 : * signal handler routines
1563 : * --------------------------------
1564 : */
1565 :
1566 : /*
1567 : * Check to see if a log rotation request has arrived. Should be
1568 : * called by postmaster after receiving SIGUSR1.
1569 : */
1570 : bool
1571 2 : CheckLogrotateSignal(void)
1572 : {
1573 : struct stat stat_buf;
1574 :
1575 2 : if (stat(LOGROTATE_SIGNAL_FILE, &stat_buf) == 0)
1576 2 : return true;
1577 :
1578 0 : return false;
1579 : }
1580 :
1581 : /*
1582 : * Remove the file signaling a log rotation request.
1583 : */
1584 : void
1585 1446 : RemoveLogrotateSignalFiles(void)
1586 : {
1587 1446 : unlink(LOGROTATE_SIGNAL_FILE);
1588 1446 : }
1589 :
1590 : /* SIGUSR1: set flag to rotate logfile */
1591 : static void
1592 2 : sigUsr1Handler(SIGNAL_ARGS)
1593 : {
1594 2 : rotation_requested = true;
1595 2 : SetLatch(MyLatch);
1596 2 : }
|
