[exim] Sleeping Somehow Makes Email Delivery Faster?!

Top Page
Delete this message
Reply to this message
Author: Kim-Alexander Brodowski
Date:  
To: exim-users
Subject: [exim] Sleeping Somehow Makes Email Delivery Faster?!
Hello fellow postmasters,

I'm experiencing a weird issue I hope somebody here can help me make
sense of.

Background:

We're using a small bash script, see below, to inform us when certain
systemd units fail. This is essentially because stuff runs in the
background and not everyone interested in the results of these tasks can
work with a terminal.

    #!/bin/bash
    if [ "$#" -ne 2 ]
    then
      echo "Usage: $(basename "$0") RECIPIENT UNIT" 1>&2
      exit 1
    fi

    . /usr/lib/iserv/cfg

    echo "Sending status report of $2 to $1 ..."

    HOSTNAME="$(hostname)"
    HOSTNAME="${HOSTNAME:-localhost}"
    MAIL_DOMAIN="${Domain:-$HOSTNAME}"
    MAIL="root@${MAIL_DOMAIN}"

    s-nail --batch-mode -s "$2" -r "$MAIL" -C "X-IServ-systemd-Unit:
$2" -. "$1" <<ERRMAIL

    $(systemctl status -n 0 --full "$2")

    $(journalctl -u "$2" --since "$(systemctl show "$2" --property
ExecMainStartTimestamp --value)")

    This message was automatically generated by $0 on $HOSTNAME.
    ERRMAIL

    #sleep 10

If anyone is interested in the corresponding unit file and config for
other units, I can provide those as well, but I don't think they provide
additional context here.

When this script is called interactively, emails generated are pretty
much instantly delivered to Cyrus, our MDA. When the script is called by
systemd, the mail instead is queued for some time by exim4 and
eventually delivered. This is where our problem lies: We prefer
instantaneous delivery in this instance.

s-nail sends its mail using sendmail, which on our platform of choice,
Debian Bullseye, is part of the exim4-daemon-heavy package.

I've traced s-nails call to sendmail and there is no difference in
arguments when being called interactively. The problem appears to be
somewhere on Exim's side.

I've enabled debug logging, but looking at the output, I don't see
anything of particular interest. I've attached an excerpt.

Now to the oddity justifying the odd subject: In the script above, there
is a sleep statement commented out. This shouldn't really do anything,
except for increasing the runtime of the bash script. However,
uncommenting that actually makes email delivery instantaneous again.
Yeah ... It almost seems like exim4 somehow speeds things up if the
calling process sticks around for some time. Maybe it feels it's being
... pressured?

Joking aside, I've looked at stuff like queue_only_load, but I don't
think these options are to blame here.

Maybe somebody has an idea of what is going wrong here. Thanks in
advance. We love Exim ;)

--
Kind regards,
Kim-Alexander Brodowski

IServ GmbH
Entwicklung
Bültenweg 73
38106 Braunschweig

Telefon:   +49 531 22 43 666-0
Fax:       +49 531 22 43 666-9
E-Mail:    Kim.Brodowski@???
Internet:  https://iserv.eu


USt-IdNr. DE265149425 | Amtsgericht Braunschweig | HRB 201822
Geschäftsführer: Benjamin Heindl, Martin Hüppe, Jörg Ludwig
Grundsätze zum Datenschutz: https://iserv.eu/privacy
warn: condition test succeeded in ACL "acl_check_notsmtp"
processing "require" (/etc/exim4/exim4.conf 134)
check add_header = X-IServ-Distribution: ${if exists {/etc/iserv/update}{${readfile{/etc/iserv/update}}}{stable}}
                 = X-IServ-Distribution: unstable


require: condition test succeeded in ACL "acl_check_notsmtp"
processing "warn" (/etc/exim4/exim4.conf 138)
direct command:
  argv[0] = '/usr/bin/dpkg-query'
  argv[1] = '-Wf'
  argv[2] = '${Version}'
  argv[3] = 'iserv-update'
fresh-exec forking for expand-run
fresh-exec forked for expand-run: 39873
postfork: expand-run
check condition = ${run{/usr/bin/dpkg-query -Wf \'\$\{Version\}\' iserv-update}{true}{false}}
                = true
check condition = ${if !eq{$value}{}{true}{false}}
                = true
check add_header = X-IServ-Update-Version: $value
                 = X-IServ-Update-Version: 100-219a3fc8
warn: condition test succeeded in ACL "acl_check_notsmtp"
processing "warn" (/etc/exim4/exim4.conf 144)
direct command:
  argv[0] = '/usr/bin/dpkg-query'
  argv[1] = '-Wf'
  argv[2] = '${Version}'
  argv[3] = 'iserv-portal'
fresh-exec forking for expand-run
fresh-exec forked for expand-run: 39874
postfork: expand-run
check condition = ${run{/usr/bin/dpkg-query -Wf \'\$\{Version\}\' iserv-portal}{true}{false}}
                = true
check condition = ${if !eq{$value}{}{true}{false}}
                = true
check add_header = X-IServ-Portal-Version: $value
                 = X-IServ-Portal-Version: 100-c818e128
warn: condition test succeeded in ACL "acl_check_notsmtp"
processing "warn" (/etc/exim4/exim4.conf 150)
direct command:
  argv[0] = '/usr/bin/dpkg-query'
  argv[1] = '-Wf'
  argv[2] = '${Version}'
  argv[3] = 'iserv-backup'
fresh-exec forking for expand-run
fresh-exec forked for expand-run: 39875
postfork: expand-run
check condition = ${run{/usr/bin/dpkg-query -Wf \'\$\{Version\}\' iserv-backup}{true}{false}}
                = true
check condition = ${if !eq{$value}{}{true}{false}}
                = true
check add_header = X-IServ-Backup-Version: $value
                 = X-IServ-Backup-Version: 100-e1d23675
warn: condition test succeeded in ACL "acl_check_notsmtp"
processing "warn" (/etc/exim4/exim4.conf 156)
direct command:
  argv[0] = '/usr/bin/dpkg-query'
  argv[1] = '-Wf'
  argv[2] = '${Version}'
  argv[3] = 'iserv-display'
fresh-exec forking for expand-run
fresh-exec forked for expand-run: 39876
postfork: expand-run
check condition = ${run{/usr/bin/dpkg-query -Wf \'\$\{Version\}\' iserv-display}{1}{0}}
                = 1
check condition = ${if !eq{$value}{}{true}{false}}
                = false
warn: condition test failed in ACL "acl_check_notsmtp"
processing "accept" (/etc/exim4/exim4.conf 162)
accept: condition test succeeded in ACL "acl_check_notsmtp"
end of ACL "acl_check_notsmtp": ACCEPT

>>Headers added by non-SMTP ACL:

X-IServ-Distribution: unstable
X-IServ-Update-Version: 100-219a3fc8
X-IServ-Portal-Version: 100-c818e128
X-IServ-Backup-Version: 100-e1d23675
>>

calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file: /var/spool/exim4//input//hdr.1o960h-000AN6-UT
DSN: **** SPOOL_OUT - address: <root@???> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
Renaming spool header file: /var/spool/exim4//input//1o960h-000AN6-UT-H
Size of headers = 669
LOG: MAIN
<= root@??? U=root P=local S=1777 id=20220706142811.veo5G%root@???
search_tidyup called
fresh-exec forking for local-accept-delivery
fresh-exec forked for local-accept-delivery: 39877
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=39872 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>

postfork: local-accept-delivery
exec /usr/sbin/exim4 -d=0xf7715cfd -MCd local-accept-delivery -Mc 1o960h-000AN6-UT