Oops. Inadvertently posted this reply in the wrong topic. Reposting it hear for proper threading.
=========== I noticed what appears to be a cosmetic problem: log entries from master are being time-stamped with the time they were last started or “postfix reload”-ed rather than the current time and log entries from qmgr are being time-stamped with the time of the first activity since the start or reload. I did a postfix reload this morning while debugging my log file rotate/compress job: Jan 23 07:16:00 albion postfix/postfix-script[61552]: refreshing the Postfix mail system Jan 22 14:43:45 albion postfix/master[45505]: reload -- version 3.4-20190121-nonprod, configuration /usr/local/etc/postfix ^^^^^^^^^^^^^^^ time of last reload Jan 23 07:30:10 albion postfix/pickup[61558]: 9C59C1032D4E: uid=501 from=<larry> Jan 23 07:30:10 albion postfix/cleanup[61784]: 9C59C1032D4E: message-id=<20190123133010.9c59c1032...@albion.stonejongleux.com> Jan 23 07:30:10 albion postfix/qmgr[61559]: 9C59C1032D4E: from=<la...@albion.stonejongleux.com>, size=1041, nrcpt=1 (queue active) Jan 23 07:30:11 albion postfix/smtp[61792]: Anonymous TLS connection established to smtp.your-site.com[205.233.73.98]:587: TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits) Jan 23 07:30:11 albion postfix/smtp[61792]: 9C59C1032D4E: to=<la...@stonejongleux.com>, relay=smtp.your-site.com[205.233.73.98]:587, delay=0.88, delays=0.12/0.16/0.44/0.16, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 43l5kW2zJ5zycF) Jan 23 07:30:10 albion postfix/qmgr[61559]: 9C59C1032D4E: removed Jan 23 07:30:10 albion postfix/pickup[61558]: 2AF4E1032E6B: uid=501 from=<larry> Jan 23 07:55:36 albion postfix/cleanup[62203]: 2AF4E1032E6B: message-id=<20190123135536.2af4e1032...@albion.stonejongleux.com> Jan 23 07:30:10 albion postfix/qmgr[61559]: 2AF4E1032E6B: from=<la...@albion.stonejongleux.com>, size=843, nrcpt=1 (queue active) ^^^^^^^^^^^^^^^ time of first activity above And from a few minutes ago to provide some greater time separation from the last reload: Jan 23 10:31:00 albion postfix/pickup[64766]: C81A61033C87: uid=501 from=<la...@stonejongleux.com> Jan 23 10:31:00 albion postfix/cleanup[64795]: C81A61033C87: message-id=<20190123163100.c81a61033...@albion.stonejongleux.com> Jan 23 07:30:10 albion postfix/qmgr[61559]: C81A61033C87: from=<la...@stonejongleux.com>, size=1590, nrcpt=1 (queue active) ^^^^^^^^^^^^^^^ time of first activity above Jan 23 10:31:01 albion postfix/smtp[64798]: Anonymous TLS connection established to smtp.your-site.com[205.233.73.98]:587: TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits) Jan 23 10:31:01 albion postfix/smtp[64798]: C81A61033C87: to=<la...@stonejongleux.com>, relay=smtp.your-site.com[205.233.73.98]:587, delay=0.63, delays=0.05/0.03/0.43/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 43l9l92Zkzz16xT) Jan 23 07:30:10 albion postfix/qmgr[61559]: C81A61033C87: removed ^^^^^^^^^^^^^^^ time of first activity above -- Larry Stone lston...@stonejongleux.com > On Jan 22, 2019, at 6:20 AM, Wietse Venema <wie...@porcupine.org> wrote: > > Viktor Dukhovni: >> On Mon, Jan 21, 2019 at 07:04:56PM -0500, Wietse Venema wrote: >> >>> postfix-3.4-20190121-nonprod-logger has lightly-tested code for >>> logging to file without using syslogd. >> >> I see that the postlogd(8) service correctly uses a unix-dgram >> service to avoid message reordering, so the usual attention to >> detail has not deserted you. :-) Thanks! > > A lot of attention to detail went into this, but I have no control > over how the kernel's unix-domain datagram implementation buffers > messages until the postlogd service is ready. That's why messages > are time-stamped by the sender, not receiver. > >> For log rotation instructions, I would add that the old file should >> not be modified, compressed or otherwise assumed complete, until a >> new file is observed to have been written by postlogd(8) after >> processing the "reload" command. If one is not sure whether Postfix >> is running, one could use postlog(1) (as root) to cause a new file >> to be written, one way or the other. > > The Postfix master immediately signals postlogd to terminate. This > being a single-instance event-driven service, it should terminate > immediately unless it is blocked on file writes. > >> The only other nit that comes to mind, is that some syslog servers >> needlessly delete and re-create their unix-dgram sockets on reload, >> which leads to needless opportunities for brief loss of messages >> written to the previous incarnation of the socket. > > The Postfix master does not close a socket, unless the service is > removed from master.cf, or master_service_disable is in effect. > > Wietse
