opendkim does not start properly when ldap server can't be contacted

[ben thielsen]

when starting opendkim, if ldap is in use and the server cannot be contacted, opendkim gets stuck in a state where the system appears to think it has started, but is not actually running:

>systemctl -l status opendkim
● opendkim.service - LSB: Start the OpenDKIM service
   Loaded: loaded (/etc/init.d/opendkim)
   Active: active (exited) since Wed 2015-05-06 23:16:20 EDT; 1min 24s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 589 ExecStart=/etc/init.d/opendkim start (code=exited, status=0/SUCCESS)

May 06 23:16:19 server systemd[1]: Starting LSB: Start the OpenDKIM service...
May 06 23:16:20 server opendkim[589]: Starting OpenDKIM: opendkim: /etc/opendkim/opendkim.conf: ldap://dsa.example.com/ou=domains,ou=mail,dc=example,dc=com?host?sub?(host=$d): dkimf_db_open(): Can't contact LDAP server
May 06 23:16:20 server opendkim[589]: opendkim.
May 06 23:16:20 server systemd[1]: Started LSB: Start the OpenDKIM service.

>ps -aefwww | grep -iF dkim
root 858 815 0 23:18 pts/0 00:00:00 grep -iF dkim

additional attempts to start opendkim don't indicate failure, but also don't work:

>systemctl start opendkim
>

>ps -aefwww | grep -iF dkim
root 863 815 0 23:19 pts/0 00:00:00 grep -iF dkim

additionally, as can be seen in the above systemctl status output, systemd appears to think that opendkim has started successfully, but when testing manually, it does not:

>/usr/sbin/opendkim -x /etc/opendkim/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid
opendkim: /etc/opendkim/opendkim.conf: ldap://dsa.example.com/ou=domains,ou=mail,dc=example,dc=com?host?sub?(host=$d): dkimf_db_open(): Can't contact LDAP server

>echo $?
78

lastly, stopping opendkim [even though it's not really running] and then starting it again then results in it actually running:

>systemctl stop opendkim

>systemctl start opendkim

>ps -aefwww | grep -iF opendkim
opendkim 1105 1 0 23:24 ? 00:00:00 /usr/sbin/opendkim -x /etc/opendkim/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid
opendkim 1106 1105 0 23:24 ? 00:00:00 /usr/sbin/opendkim -x /etc/opendkim/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid
root 1117 815 0 23:25 pts/0 00:00:00 grep -iF opendkim

[Scott Kitterman (kitterman)]

I can't replicate this on an older release with upstart instead of systemd.

service opendkim start
Starting OpenDKIM: opendkim: /etc/opendkim.conf: ldap://192.0.2.1/ou=people,dc=example,dc=com?DKIMSelector?sub?(DKIMIdentity=$d): dkimf_db_open(): Can't contact LDAP server
opendkim.
# ps -AF|grep opendkim
opendkim 677 1 0 63960 1648 0 Apr30 ? 00:00:01 rsyslogd
root 3012 12880 0 2216 648 1 00:11 pts/4 00:00:00 grep opendkim
# service opendkim status
 * opendkim is not running

I suspect this is a systemd issue.

As a workaround, you might add SoftStart true to your opendkim.conf. That should cause it to start normally without LDAP.

[ben thielsen (btb-bitrate)]

thanks for this. i'd tried LDAPSoftStart, which didn't work, missing that it had been renamed. i've added SoftStart yes to the config, but the behavior seems to be the same.

i can corroborate that this seems new with 15.04/systemd. another older system like yours works ok.

[ben thielsen (btb-bitrate)]

some additional detail regarding SoftStart - it seems to not be working right [systemd issues excluded]:

>egrep -v '(^[[:space:]]*#|^[[:space:]]*$)' opendkim.conf
Syslog yes
SyslogSuccess yes
LogWhy yes
UMask 002
BaseDirectory /etc/opendkim
Socket inet:dkim-filter@localhost
Mode s
Quarantine no
RemoveOldSignatures no
SubDomains no
SoftStart yes
LDAPUseTLS yes
LDAPBindUser cn=opendkim,ou=exo,ou=services,ou=accounts,dc=example,dc=com
LDAPBindPassword xxxxxxxxxxxxxxxxxx
InternalHosts localhost, 192.0.2.1
Selector default
KeyFile /etc/opendkim/keys/default-private_key.pem
Domain ldap://dsa.example.com/ou=domains,ou=mail,dc=example,dc=com?host?sub?(host=$d)

>/usr/sbin/opendkim -x /etc/opendkim/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid
opendkim: /etc/opendkim/opendkim.conf: ldap://dsa.example.com/ou=domains,ou=mail,dc=example,dc=com?host?sub?(host=$d): dkimf_db_open(): Can't contact LDAP server

>echo $?
78

according to the init script, exit status 78 indicates a configuration error?

[ben thielsen (btb-bitrate)]

it seems like in addition to the softstart issue, the init script is in need of some attention?

it runs start-stop-daemon to check the config and start the process, but both commands are or'd with a return 1 or return 2. the check to handle exit status 78 can never happen, because the only way it will continue in that function is if the exit status for both start-stop-daemon commands is 0.

then, regardless of any of that, the script exits 0 no matter what, so systemd never knows something didn't go right. it's left thinking the service is running, but it's not. when the init script is changed to exit with the exit status of dkim, then systemd knows what's going on and handles the outcome as expected.

[Scott Kitterman (kitterman)]

I wonder if this might be similar to
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1447807 in some way.
Perhaps you could test the package in vivid-proposed once it's built and see
if the problem is still there.

[Martin Pitt (pitti)]

@Scott: bug 1447807 is different.

Ben Thielsen has it exactly right: the init.d script entirely ignores the return value of start-stup-daemon. It neither has an upstart job nor systemd unit, so systemd and upstart call the init.d script and rely on its exit code.

[ben thielsen (btb-bitrate)]

i've addressed this, from my perspective, by switching to an independent systemd unit file:

>cat /etc/systemd/system/opendkim.service
[Unit]
Description=DomainKeys Identified Mail (DKIM) Milter
Documentation=man:opendkim(8) man:opendkim.conf(5) man:opendkim-genkey(8) man:opendkim-genzone(8) man:opendkim-testadsp(8) man:opendkim-testkey http://www.opendkim.org/docs.html
After=network.target nss-lookup.target syslog.target

[Service]
Type=forking
PIDFile=/run/opendkim/opendkim.pid
EnvironmentFile=-/etc/default/opendkim
ExecStart=/usr/sbin/opendkim -x /etc/opendkim/opendkim.conf
TimeoutStartSec=10
ExecReload=/bin/kill -USR1 $MAINPID
User=opendkim
Group=opendkim

[Install]
WantedBy=multi-user.target

this was built from the sample in the opendkim source [/contrib/systemd/]

i'll file a separate bug for the SoftStart issue i'm having.

[ben thielsen (btb-bitrate)]

i neglect to provide accommodations for creation of /run/opendkim - here is an amended systemd unit file:

[Unit]
Description=DomainKeys Identified Mail (DKIM) Milter
Documentation=man:opendkim(8) man:opendkim.conf(5) man:opendkim-genkey(8) man:opendkim-genzone(8) man:opendkim-testadsp(8) man:opendkim-testkey http://www.opendkim.org/docs.html
After=network.target nss-lookup.target syslog.target

[Service]
Type=forking
User=opendkim
Group=opendkim
PermissionsStartOnly=true
EnvironmentFile=-/etc/default/opendkim
PIDFile=/run/opendkim/opendkim.pid
ExecStartPre=-/bin/mkdir /run/opendkim
ExecStartPre=-/bin/chown opendkim.opendkim /run/opendkim
ExecStart=/usr/sbin/opendkim -x /etc/opendkim/opendkim.conf
TimeoutStartSec=10
ExecReload=/bin/kill -USR1 $MAINPID

[Install]
WantedBy=multi-user.target

[Scott Kitterman (kitterman)]

I'm gong to ship a service file based on yours in the next opendkim upload to Debian which should, when synced to Ubuntu, resolve this. Thanks for providing the example.

[Launchpad Janitor (janitor)]

This bug was fixed in the package opendkim - 2.10.3-2

---------------
opendkim (2.10.3-2) unstable; urgency=medium

  * Ship systemd service file along with sysv init (LP: #1452538)
  * Fix upstream service file to recreate /var/run/opendkim on boot and to use
    appropriate paths for Debian
    - Thanks to Ben Thielsen for the patch

 -- Scott Kitterman <email address hidden> Sun, 05 Jul 2015 14:50:56 -0400