• Bug#1106030: logcheck: mails from the systemd timer are delayed by up t

    From Richard Lewis@21:1/5 to All on Mon May 19 00:20:01 2025
    package: logcheck
    version: 1.4.4

    (following investigation of #1105792 , which i could not reproduce -
    but maybe this is relevant)

    This assumes exim, but i believe applies to postfix as well.

    The systemd timer works "fine", but the mail is actually being
    delayed. If you do

    # tail -n0 -f /var/log/exim4/mainlog &
    # logger bad && systemctl start logcheck
    2025-05-18 22:31:06 1uGlb8-000000000iC-35Cw <= logcheck@mailname
    U=logcheck P=local S=2858

    you see there is only one line in exim's mainlog: the mail was passed
    to exim OK, but was not immediately delivered. The mail is actually
    stuck in a queue:

    # mailq
    2m 2.8K 1uGlb8-000000000iC-35Cw <logcheck@mailname>
    logcheck@mailname

    the delivery only happens once exim does its regular queue-running (or
    you can do 'runq' to deliver immediately) - this happens every 30
    minutes by default. You can probably also see the delay in the
    'Received' headers.

    Adding a sleep to the systemd service fixes this:

    # systemctl edit logcheck.service

    [Service]
    ExecStart=sleep 10

    and then you will see that the mail is also delivered right after logcheck runs.
    (i found even a sleep 0.5 was enough, but maybe it depends on <something>):

    # logger good && systemctl start logcheck
    2025-05-18 22:42:13 1uGllt-000000000NK-33ae <= logcheck@mailname
    U=logcheck P=local S=10245
    2025-05-18 22:42:13 1uGllt-000000000NK-33ae => user
    <logcheck@mailname> R=local_user T=mail_spool
    2025-05-18 22:42:13 1uGllt-000000000NK-33ae Completed

    no delay.

    As i said in #1105792, i think this is to do with systemd and exim
    taking a somewhat incompatible approach, -- see https://systemd-devel.freedesktop.narkive.com/nV1QMO8j/exim4-only-queues-mails-sent-by-systemd-service

    i thought this was an issue when adding hardening to the unit, but it
    seems to happen anyway - it's easy to miss as the "From" header doesnt
    show there was any delay.

    A "workaround fix" could be to add a "ExecStart=sleep 10" to the logcheck.service.

    --- SoupGate-Win32 v1.05
    * Origin: fsxNet Usenet Gateway (21:1/5)
  • From Mathias Gibbens@21:1/5 to All on Mon May 19 18:00:01 2025
    control: tags -1 + confirmed pending

    That is interesting, and I see the same thing when I inspect some of
    the logcheck emails sent via exim. On my server running postfix I don't
    see this behavior.

    Adding a post-run sleep seems a bit hacky, but it won't negatively
    impact anything either and will resolve this issue.

    Mathias

    -----BEGIN PGP SIGNATURE-----

    iQIzBAABCgAdFiEE1Bp60H32xfynSJ8cKe7i1uz0QvkFAmgrVHEACgkQKe7i1uz0 Qvm1GBAAsNFfrpE0wIN9KezBcUCLi4y8mNGF50G7K3bR1GHZW0ZWVLoow2vikei0 3S3UTaGjwkYC1XPFwoj2wRZfqLMQIx2w2JyF+wyaKongr46H4F83cEZJVCNp3jBf ilBasJxmuo93zF7YO27eTNgyQiIHJ/U2kUXj+GmJAfSnocEV+opghIdVrFJsrWB8 c+ajZVsksIKbwsMqoY7dB/Cw1txB6OaaxzXcPvAx7rTb2jfp6OVW9IT8J8IlhBIZ PEcNbeHHwQrSV2tpvw09Eg3XmrNkEYxehq//Ton77MfYXgIuhZqEnPy6gq+qshSg Ce3dpXkyVcONCrz3LNNfXFmDCpx6F+MPvmVzh2ERthKzV/uJIAtZOKBR/RkIGwam X5N4QMntyiWfdUQ9Hys6dDjCDHP8RsWbH+3ch30sWt4uE5Coe9jFgoZtdoFlKCjB T8IYtR5evU5y3stuqBxeLG1yJK2rdsM43m69wfCdoRVaInzjvkXhTAVeYCrUDhtI TrJ96tIk0uweRFScIlIgqAGb64r2Z8ZbBebYpZHw5xeYKRBM6OCFDSASa4YLQmHV 5/ENrrdYknvlwnYi+UwgTkGbboJXbMeBmwTDhM8D2U9BNFS1ni2sqVUOysffSttr IiIfAbnyT3eu+j1JSjabrX0H+6leibJBIqTuc20AlFy9HOh4z90=
    =L7xp
    -----END PGP SIGNATURE-----

    --- SoupGate-Win32 v1.05
    * Origin: fsxNet Usenet Gateway (21:1/5)