While testing some patches on my laptop, I noticed my knee getting
uncomfortably warm. It turns out I has accumulating deranged logging
processes, needing kill -9 to get rid of them.
The culprit is:
commit c4901a1e03a7730e4471fd1143f1caf79695493d
Author: Andres Freund <andres@anarazel.de>
Date: Fri Mar 18 11:43:59 2016 -0700
Only clear latch self-pipe/event if there is a pending notification.
All I need to do to reproduce it is turn logging_collector = on,
then:
pg_ctl start
pg_ctl stop
A strace of a logger process shows:
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771863) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771862) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771862) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771862) = 1
([{fd=7, revents=POLLHUP}])
poll([{fd=10, events=POLLIN}, {fd=7, events=POLLIN}], 2, 9771862) = 1
([{fd=7, revents=POLLHUP}])
And a backtrace shows:
(gdb) bt full
#0 0x00007fce93f90050 in __poll_nocancel () from /lib64/libc.so.6
No symbol table info available.
#1 0x000000000065a52a in WaitLatchOrSocket (latch=0xc179c4
<LocalLatchData>, wakeEvents=11, sock=7, timeout=7259000) at
pg_latch.c:350 result = 0 rc = <optimized out> start_time = {tv_sec = 1458363541, tv_usec = 583339}
cur_time = {tv_sec = 19, tv_usec = 795497} cur_timeout = 7239205 pfds = {{fd = 10, events = 1, revents =
0},{fd = 7, events =
1, revents = 16}, {fd = 222842297, events = 32766, revents = 0}} nfds = 2 __func__ = "WaitLatchOrSocket"
#2 0x000000000066b64f in SysLoggerMain (argv=<optimized out>,
argc=<optimized out>) at syslogger.c:424 time_based_rotation = <optimized out> size_rotation_for =
<optimizedout> cur_timeout = <optimized out> rc = <optimized out> logbuffer =
"\000\000K\000\362\021\000\000t4594 00000
2016-03-18 21:59:01.583 PDT LOG: database system is shut
down\nbuffers (0.0%); 0 transaction log file(s) added, 0 removed, 0
recycled; write=0.000 s, sync=0.000 s, total=0.001 s; "... bytes_in_logbuffer = 0 currentLogDir = 0x26ef130
"pg_log" currentLogFilename = 0x26ef200 "postgresql-%Y-%m-%d_%H%M%S.log" currentLogRotationAge = 1440
now= 1458363541
#3 0x000000000066bdfb in SysLogger_Start () at syslogger.c:600 sysloggerPid = 0 filename = 0x0
__func__= "SysLogger_Start"
#4 0x000000000066a878 in PostmasterMain (argc=argc@entry=1,
argv=argv@entry=0x26d5a10) at postmaster.c:1208 opt = <optimized out> status = <optimized out>
userDoption= <optimized out> listen_addr_saved = <optimized out> i = <optimized out>
output_config_variable= <optimized out> __func__ = "PostmasterMain"
#5 0x000000000047cd1e in main (argc=1, argv=0x26d5a10) at main.c:228
Cheers,
Jeff