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