Gave it another 10 mins, this time checking the 'receiving' end, being rsyslog in my case: [pid 583] <... select resumed> ) = 1 (in [0]) [pid 583] recvmsg(0, {msg_name(0)=NULL, msg_iov(1)=[{"<86>Jun 9 10:01:01 CRON[4860]: pam_unix(cron:session): session opened for user sogo by (uid=0)", 8096}], msg_controllen=64, {cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=0x1d /* SCM_??? */, ...}, msg_flags=0}, MSG_DONTWAIT) = 95 [pid 583] futex(0x73de74, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x73de70, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} [pid 585] <... futex resumed> ) = 0 [pid 583] <... futex resumed> ) = 1 [pid 585] futex(0x73e060, FUTEX_WAIT_PRIVATE, 2, NULL [pid 583] futex(0x73e060, FUTEX_WAKE_PRIVATE, 1 [pid 585] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 583] <... futex resumed> ) = 0 [pid 585] futex(0x73e060, FUTEX_WAKE_PRIVATE, 1 [pid 583] select(4, [0 3], NULL, NULL, NULL [pid 585] <... futex resumed> ) = 0 [pid 585] write(5, "Jun 9 10:01:01 mail1 CRON[4860]: pam_unix(cron:session): session opened for user sogo by (uid=0)\n", 98) = 98 [pid 585] write(1, "May 30 19:38:01 mail1 CRON[4860]: message repeated 3 times: [ (sogo) CMD (/usr/sbin/sogo-ealarms-notify && /usr/sbin/sogo-tool expire-sessions 60)]\n", 148) = 148 [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory) [pid 585] open("/dev/xconsole", O_RDWR|O_NONBLOCK|O_CLOEXEC [pid 583] <... select resumed> ) = 1 (in [0]) [pid 585] <... open resumed> ) = -1 ENOENT (No such file or directory) [pid 583] recvmsg(0, [pid 585] futex(0x73de74, FUTEX_WAIT_PRIVATE, 2668217, NULL [pid 583] <... recvmsg resumed> {msg_name(0)=NULL, msg_iov(1)=[{"<78>Jun 9 10:01:01 CRON[4861]: (sogo) CMD (/usr/sbin/sogo-ealarms-notify && /usr/sbin/sogo-tool expire-sessions 60)", 8096}], msg_controllen=64, {cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=0x1d /* SCM_??? */, ...}, msg_flags=0}, MSG_DONTWAIT) = 116 [pid 585] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 583] futex(0x73de74, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x73de70, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} [pid 585] futex(0x73e060, FUTEX_WAIT_PRIVATE, 2, NULL [pid 583] <... futex resumed> ) = 0 [pid 585] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 583] futex(0x73e060, FUTEX_WAKE_PRIVATE, 1 [pid 585] futex(0x73e060, FUTEX_WAKE_PRIVATE, 1 [pid 583] <... futex resumed> ) = 0 [pid 585] <... futex resumed> ) = 0 [pid 583] select(4, [0 3], NULL, NULL, NULL [pid 585] write(1, "Jun 9 10:01:01 mail1 CRON[4861]: (sogo) CMD (/usr/sbin/sogo-ealarms-notify && /usr/sbin/sogo-tool expire-sessions 60)\n", 119) = 119 [pid 585] futex(0x73de74, FUTEX_WAIT_PRIVATE, 2668219, NULL [pid 583] <... select resumed> ) = 1 (in [0]) [pid 583] recvmsg(0, {msg_name(0)=NULL, msg_iov(1)=[{"<86>Jun 9 10:01:01 CRON[4860]: pam_unix(cron:session): session closed for user sogo", 8096}], msg_controllen=64, {cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=0x1d /* SCM_??? */, ...}, msg_flags=0}, MSG_DONTWAIT) = 84 [pid 583] futex(0x73de74, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x73de70, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} [pid 585] <... futex resumed> ) = 0 [pid 583] <... futex resumed> ) = 1 [pid 585] futex(0x73e060, FUTEX_WAKE_PRIVATE, 1 [pid 583] select(4, [0 3], NULL, NULL, NULL [pid 585] <... futex resumed> ) = 0 [pid 585] write(5, "Jun 9 10:01:01 mail1 CRON[4860]: pam_unix(cron:session): session closed for user sogo\n", 87) = 87 [pid 585] futex(0x73de74, FUTEX_WAIT_PRIVATE, 2668221, NULL From this I can see I need to comment out this darn xconsole in /etc/rsyslog.d/50-default.conf since this is a vm. But the more interesting thing is of course: recvmsg -> pam session open -> write the same to syslog files recvmsg -> cron cmd -> write the same to syslog recvmsg -> pam session closed -> write to syslog But in this instance where things mess up, I'm seeing: recvmsg -> pam session open -> write to syslog (still all good) (no matching recvmsg) cron cmd -> write to syslog (wrong date/time, same cron pid from session open, repeated 3 times ???) recvmsg -> cron cmd (sane pid again) -> write to syslog (all good) recvmsg -> pam session closed -> write to syslog (all good) So I doubt this has anything to do with cron, pretty much convinced it's in rsyslog. And then the question is, is this some rsyslog bug or misconfiguration, which imho should still not cause anything like this to happen. With misconfig I mean the xconsole maybe causing some race but I'd have to monitor a bit further then for this to happen at the right time. Right time as in, most likely around the same time this particular cron starts. And the reporter of this bug mentioned restarting cron did not help, only rebooting helps. That would make sense since everything points at rsyslog and not cron. So I will also try restarting just rsyslog and see what that brings before things go nuts again ;-)