Location via proxy:   [ UP ]  
[Report a bug]   [Manage cookies]                
Skip to content

Commit 398b240

Browse files
committed
Avoid unnecessary process wakeups in the log collector.
syslogger was coded to wake up once per second whether there was anything useful to do or not. As part of our campaign to reduce the server's idle power consumption, change it to use a latch for waiting. Now, in the absence of any data to log or any signals to service, it will only wake up at the programmed logfile rotation times (if any).
1 parent 7b85527 commit 398b240

File tree

1 file changed

+66
-29
lines changed

1 file changed

+66
-29
lines changed

src/backend/postmaster/syslogger.c

Lines changed: 66 additions & 29 deletions
Original file line numberDiff line numberDiff line change
@@ -9,8 +9,7 @@
99
* in postgresql.conf. If these limits are reached or passed, the
1010
* current logfile is closed and a new one is created (rotated).
1111
* The logfiles are stored in a subdirectory (configurable in
12-
* postgresql.conf), using an internal naming scheme that mangles
13-
* creation time and current postmaster pid.
12+
* postgresql.conf), using a user-selectable naming scheme.
1413
*
1514
* Author: Andreas Pflug <pgadmin@pse-consulting.de>
1615
*
@@ -40,6 +39,7 @@
4039
#include "postmaster/postmaster.h"
4140
#include "postmaster/syslogger.h"
4241
#include "storage/ipc.h"
42+
#include "storage/latch.h"
4343
#include "storage/pg_shmem.h"
4444
#include "utils/guc.h"
4545
#include "utils/ps_status.h"
@@ -93,6 +93,7 @@ static FILE *syslogFile = NULL;
9393
static FILE *csvlogFile = NULL;
9494
static char *last_file_name = NULL;
9595
static char *last_csv_file_name = NULL;
96+
static Latch sysLoggerLatch;
9697

9798
/*
9899
* Buffers for saving partial messages from different backends.
@@ -168,12 +169,14 @@ SysLoggerMain(int argc, char *argv[])
168169
char *currentLogDir;
169170
char *currentLogFilename;
170171
int currentLogRotationAge;
172+
pg_time_t now;
171173

172174
IsUnderPostmaster = true; /* we are a postmaster subprocess now */
173175

174176
MyProcPid = getpid(); /* reset MyProcPid */
175177

176178
MyStartTime = time(NULL); /* set our start time in case we call elog */
179+
now = MyStartTime;
177180

178181
#ifdef EXEC_BACKEND
179182
syslogger_parseArgs(argc, argv);
@@ -246,6 +249,9 @@ SysLoggerMain(int argc, char *argv[])
246249
elog(FATAL, "setsid() failed: %m");
247250
#endif
248251

252+
/* Initialize private latch for use by signal handlers */
253+
InitLatch(&sysLoggerLatch);
254+
249255
/*
250256
* Properly accept or ignore signals the postmaster might send us
251257
*
@@ -296,14 +302,19 @@ SysLoggerMain(int argc, char *argv[])
296302
{
297303
bool time_based_rotation = false;
298304
int size_rotation_for = 0;
305+
long cur_timeout;
306+
int cur_flags;
299307

300308
#ifndef WIN32
301-
int bytesRead;
302309
int rc;
303-
fd_set rfds;
304-
struct timeval timeout;
305310
#endif
306311

312+
/* Clear any already-pending wakeups */
313+
ResetLatch(&sysLoggerLatch);
314+
315+
/*
316+
* Process any requests or signals received recently.
317+
*/
307318
if (got_SIGHUP)
308319
{
309320
got_SIGHUP = false;
@@ -353,11 +364,10 @@ SysLoggerMain(int argc, char *argv[])
353364
}
354365
}
355366

356-
if (!rotation_requested && Log_RotationAge > 0 && !rotation_disabled)
367+
if (Log_RotationAge > 0 && !rotation_disabled)
357368
{
358369
/* Do a logfile rotation if it's time */
359-
pg_time_t now = (pg_time_t) time(NULL);
360-
370+
now = (pg_time_t) time(NULL);
361371
if (now >= next_rotation_time)
362372
rotation_requested = time_based_rotation = true;
363373
}
@@ -389,28 +399,40 @@ SysLoggerMain(int argc, char *argv[])
389399
logfile_rotate(time_based_rotation, size_rotation_for);
390400
}
391401

392-
#ifndef WIN32
393-
394402
/*
395-
* Wait for some data, timing out after 1 second
403+
* Calculate time till next time-based rotation, so that we don't
404+
* sleep longer than that. We assume the value of "now" obtained
405+
* above is still close enough. Note we can't make this calculation
406+
* until after calling logfile_rotate(), since it will advance
407+
* next_rotation_time.
396408
*/
397-
FD_ZERO(&rfds);
398-
FD_SET(syslogPipe[0], &rfds);
399-
400-
timeout.tv_sec = 1;
401-
timeout.tv_usec = 0;
402-
403-
rc = select(syslogPipe[0] + 1, &rfds, NULL, NULL, &timeout);
404-
405-
if (rc < 0)
409+
if (Log_RotationAge > 0 && !rotation_disabled)
406410
{
407-
if (errno != EINTR)
408-
ereport(LOG,
409-
(errcode_for_socket_access(),
410-
errmsg("select() failed in logger process: %m")));
411+
if (now < next_rotation_time)
412+
cur_timeout = (next_rotation_time - now) * 1000L; /* msec */
413+
else
414+
cur_timeout = 0;
415+
cur_flags = WL_TIMEOUT;
411416
}
412-
else if (rc > 0 && FD_ISSET(syslogPipe[0], &rfds))
417+
else
413418
{
419+
cur_timeout = -1L;
420+
cur_flags = 0;
421+
}
422+
423+
/*
424+
* Sleep until there's something to do
425+
*/
426+
#ifndef WIN32
427+
rc = WaitLatchOrSocket(&sysLoggerLatch,
428+
WL_LATCH_SET | WL_SOCKET_READABLE | cur_flags,
429+
syslogPipe[0],
430+
cur_timeout);
431+
432+
if (rc & WL_SOCKET_READABLE)
433+
{
434+
int bytesRead;
435+
414436
bytesRead = read(syslogPipe[0],
415437
logbuffer + bytes_in_logbuffer,
416438
sizeof(logbuffer) - bytes_in_logbuffer);
@@ -445,16 +467,18 @@ SysLoggerMain(int argc, char *argv[])
445467

446468
/*
447469
* On Windows we leave it to a separate thread to transfer data and
448-
* detect pipe EOF. The main thread just wakes up once a second to
449-
* check for SIGHUP and rotation conditions.
470+
* detect pipe EOF. The main thread just wakes up to handle SIGHUP
471+
* and rotation conditions.
450472
*
451473
* Server code isn't generally thread-safe, so we ensure that only one
452474
* of the threads is active at a time by entering the critical section
453475
* whenever we're not sleeping.
454476
*/
455477
LeaveCriticalSection(&sysloggerSection);
456478

457-
pg_usleep(1000000L);
479+
(void) WaitLatch(&sysLoggerLatch,
480+
WL_LATCH_SET | cur_flags,
481+
cur_timeout);
458482

459483
EnterCriticalSection(&sysloggerSection);
460484
#endif /* WIN32 */
@@ -957,7 +981,7 @@ write_syslogger_file(const char *buffer, int count, int destination)
957981
/*
958982
* Worker thread to transfer data from the pipe to the current logfile.
959983
*
960-
* We need this because on Windows, WaitForSingleObject does not work on
984+
* We need this because on Windows, WaitforMultipleObjects does not work on
961985
* unnamed pipes: it always reports "signaled", so the blocking ReadFile won't
962986
* allow for SIGHUP; and select is for sockets only.
963987
*/
@@ -1010,6 +1034,9 @@ pipeThread(void *arg)
10101034
/* if there's any data left then force it out now */
10111035
flush_pipe_input(logbuffer, &bytes_in_logbuffer);
10121036

1037+
/* set the latch to waken the main thread, which will quit */
1038+
SetLatch(&sysLoggerLatch);
1039+
10131040
LeaveCriticalSection(&sysloggerSection);
10141041
_endthread();
10151042
return 0;
@@ -1285,12 +1312,22 @@ set_next_rotation_time(void)
12851312
static void
12861313
sigHupHandler(SIGNAL_ARGS)
12871314
{
1315+
int save_errno = errno;
1316+
12881317
got_SIGHUP = true;
1318+
SetLatch(&sysLoggerLatch);
1319+
1320+
errno = save_errno;
12891321
}
12901322

12911323
/* SIGUSR1: set flag to rotate logfile */
12921324
static void
12931325
sigUsr1Handler(SIGNAL_ARGS)
12941326
{
1327+
int save_errno = errno;
1328+
12951329
rotation_requested = true;
1330+
SetLatch(&sysLoggerLatch);
1331+
1332+
errno = save_errno;
12961333
}

0 commit comments

Comments
 (0)