Bug#792458: opendkim init script failed on start

[Cyrille Mescam]

Package: opendkim
Version: 2.10.3-3
Severity: important

Dear Maintainer,

*** Reporter, please consider answering these questions, where appropriate ***

* What led up to the situation?

After upgrading opendkim, the service is not able to start.

* What exactly did you do (or not do) that was effective (or
ineffective)?

Trying to start the service: service opendkim start

* What was the outcome of this action?

Job for opendkim.service failed because the control process exited with error code. See "systemctl status opendkim.service" and "journalctl -xe" for details.

* What outcome did you expect instead?

The service should have started.

Looking into logs, it seems that it is a command line options problem (example from /var/log/daemon.log):

Jul 15 00:18:07 sd-72405 systemd[1]: Starting DomainKeys Identified Mail (DKIM) Milter...
Jul 15 00:18:07 sd-72405 opendkim[18070]: opendkim: usage: opendkim -p socketfile [options]
Jul 15 00:18:07 sd-72405 opendkim[18070]: -A #011auto-restart
Jul 15 00:18:07 sd-72405 opendkim[18070]: -b modes #011select operating modes
Jul 15 00:18:07 sd-72405 opendkim[18070]: -c canon #011canonicalization to use when signing
Jul 15 00:18:07 sd-72405 opendkim[18070]: -d domlist #011domains to sign
Jul 15 00:18:07 sd-72405 opendkim[18070]: -D #011also sign subdomains
Jul 15 00:18:07 sd-72405 opendkim[18070]: -e name #011extract configuration value and exit
Jul 15 00:18:07 sd-72405 opendkim[18070]: -f #011don't fork-and-exit
Jul 15 00:18:07 sd-72405 opendkim[18070]: -F time #011fixed timestamp to use when signing (test mode only)
Jul 15 00:18:07 sd-72405 opendkim[18070]: -k keyfile #011location of secret key file
Jul 15 00:18:07 sd-72405 opendkim[18070]: -l #011log activity to system log
Jul 15 00:18:07 sd-72405 opendkim[18070]: -L limit #011signature limit requirements
Jul 15 00:18:07 sd-72405 opendkim[18070]: -n #011check configuration and exit
Jul 15 00:18:07 sd-72405 opendkim[18070]: -o hdrlist #011list of headers to omit from signing
Jul 15 00:18:07 sd-72405 opendkim[18070]: -P pidfile #011file into which to write process ID
Jul 15 00:18:07 sd-72405 opendkim[18070]: -q #011quarantine messages that fail to verify
Jul 15 00:18:07 sd-72405 opendkim[18070]: -Q #011query test mode
Jul 15 00:18:07 sd-72405 opendkim[18070]: -r #011require basic RFC5322 header compliance
Jul 15 00:18:07 sd-72405 opendkim[18070]: -s selector #011selector to use when signing
Jul 15 00:18:07 sd-72405 opendkim[18070]: -S signalg #011signature algorithm to use when signing
Jul 15 00:18:07 sd-72405 opendkim[18070]: -t testfile #011evaluate RFC5322 message in "testfile"
Jul 15 00:18:07 sd-72405 opendkim[18070]: -T timeout #011DNS timeout (seconds)
Jul 15 00:18:07 sd-72405 opendkim[18070]: -u userid #011change to specified userid
Jul 15 00:18:07 sd-72405 opendkim[18070]: -v #011increase verbosity during testing
Jul 15 00:18:07 sd-72405 opendkim[18070]: -V #011print version number and terminate
Jul 15 00:18:07 sd-72405 opendkim[18070]: -W #011"why?!" mode (log sign/verify decision logic)
Jul 15 00:18:07 sd-72405 opendkim[18070]: -x conffile #011read configuration from conffile
Jul 15 00:18:07 sd-72405 systemd[1]: opendkim.service: Control process exited, code=exited status=64
Jul 15 00:18:07 sd-72405 systemd[1]: Failed to start DomainKeys Identified Mail (DKIM) Milter.
Jul 15 00:18:07 sd-72405 systemd[1]: opendkim.service: Unit entered failed state.
Jul 15 00:18:07 sd-72405 systemd[1]: opendkim.service: Failed with result 'exit-code'.

I've tried to play with init script to hardcode the options, but it does work neither.

Package: opendkim
Versions:
2.10.3-3 (/var/lib/apt/lists/ftp.fr.debian.org_debian_dists_testing_main_binary-amd64_Packages) (/var/lib/dpkg/status)


/etc/init.d/opendkim changed:
PATH=/sbin:/bin:/usr/sbin:/usr/bin
DAEMON=/usr/sbin/opendkim
NAME=opendkim
DESC="OpenDKIM"
RUNDIR=/var/run/$NAME
USER=opendkim
GROUP=opendkim
PIDFILE=$RUNDIR/$NAME.pid
stoptimeout=5
test -x $DAEMON || exit 0
. /lib/lsb/init-functions
if [ -f /etc/default/opendkim ] ; then
. /etc/default/opendkim
fi
DAEMON_OPTS="-p local:/var/spool/postfix/var/run/opendkim/opendkim.sock -P $PIDFILE -x /etc/opendkim.conf -u $USER"
start() {
# Create the run directory if it doesn't exist
if [ ! -d "$RUNDIR" ]; then
install -o "$USER" -g "$GROUP" -m 755 -d "$RUNDIR" || exit 2
if pathfind restorecon; then restorecon "$RUNDIR"
fi
fi
# Clean up stale sockets
if [ -f "$PIDFILE" ]; then
pid=`cat $PIDFILE`
if ! ps -C "$NAME" -s "$pid" >/dev/null; then
rm "$PIDFILE"
TMPSOCKET=""
if [ -n "$SOCKET" ]; then
TMPSOCKET="$SOCKET"
elif [ -n "$CONFIG_SOCKET" ]; then
TMPSOCKET="$CONFIG_SOCKET"
fi
if [ -n "$TMPSOCKET" ]; then
# UNIX sockets may be specified with or without the
# local: prefix; handle both
t=`echo $SOCKET | cut -d: -f1`
s=`echo $SOCKET | cut -d: -f2`
if [ -e "$s" -a -S "$s" ]; then
if [ "$t" = "$s" -o "$t" = "local" ]; then
rm "$s"
fi
fi
fi
fi
fi
#start-stop-daemon --start --quiet --pidfile "$PIDFILE" --exec "$DAEMON" --test -- $DAEMON_OPTS || exit 1
start-stop-daemon --start --quiet --pidfile "$PIDFILE" --exec "$DAEMON" -- "$DAEMON_OPTS" || exit 2
# Detect exit status 78 (configuration error)
ret=$?
if [ $ret -eq 78 ]; then
echo "See /usr/share/doc/opendkim/README.Debian for help"
echo "Starting for DKIM verification only"
DAEMON_OPTS="-b v $DAEMON_OPTS"
start-stop-daemon --start --quiet --pidfile "$PIDFILE" --exec "$DAEMON" -- $DAEMON_OPTS
exit 0
elif [ $ret -ne 0 ]; then
exit $ret
fi
}
stop() {
start-stop-daemon --stop --retry "$stoptimeout" --exec "$DAEMON"
[ "$?" = 2 ] && exit 2
}
reload() {
start-stop-daemon --stop --signal USR1 --exec "$DAEMON"
}
status() {
local pidfile daemon name status
pidfile=
OPTIND=1
while getopts p: opt ; do
case "$opt" in
p) pidfile="$OPTARG";;
esac
done
shift $(($OPTIND - 1))
if [ -n "$pidfile" ]; then
pidfile="-p $pidfile"
fi
daemon="$1"
name="$2"
status="0"
pidofproc $pidfile $daemon >/dev/null || status="$?"
if [ "$status" = 0 ]; then
log_success_msg "$name is running"
return 0
else
log_failure_msg "$name is not running"
exit $status
fi
}
case "$1" in
start)
echo -n "Starting $DESC: $DAEMON_OPTS"
start
echo "$NAME."
;;
stop)
echo -n "Stopping $DESC: "
stop
echo "$NAME."
;;
restart)
echo -n "Restarting $DESC: "
stop
start
echo "$NAME."
;;
reload|force-reload)
echo -n "Restarting $DESC: "
reload
echo "$NAME."
;;
status)
status $DAEMON $NAME
;;
*)
N=/etc/init.d/$NAME
echo "Usage: $N {start|stop|restart|reload|force-reload|status}" >&2
exit 1
;;
esac
exit 0


-- System Information:
Debian Release: stretch/sid
APT prefers testing
APT policy: (500, 'testing'), (500, 'oldstable')
Architecture: amd64 (x86_64)

Kernel: Linux 3.16.0-4-amd64 (SMP w/8 CPU cores)
Locale: LANG=fr_FR.UTF-8, LC_CTYPE=fr_FR.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages opendkim depends on:
ii adduser 3.113+nmu3
ii dns-root-data 2014060201+2
ii init-system-helpers 1.23
ii libbsd0 0.7.0-2
ii libc6 2.19-18
ii libdb5.3 5.3.28-9
ii libldap-2.4-2 2.4.40+dfsg-2
ii liblua5.1-0 5.1.5-7.1
ii libmemcached11 1.0.18-4
ii libmemcachedutil2 1.0.18-4
ii libmilter1.0.1 8.14.9-2
ii libopendbx1 1.4.6-8
ii libopendkim10 2.10.3-3
ii librbl1 2.10.3-3
ii libssl1.0.0 1.0.2d-1
ii libunbound2 1.4.22-3
ii libvbr2 2.10.3-3
ii lsb-base 4.1+Debian13+nmu1

opendkim recommends no packages.

Versions of packages opendkim suggests:
ii opendkim-tools 2.10.3-3
pn unbound <none>

-- Configuration Files:
/etc/default/opendkim changed:
SOCKET="local:/var/spool/postfix/var/run/opendkim/opendkim.sock" # default

/etc/opendkim.conf changed:
Syslog yes
SyslogSuccess yes
LogWhy yes
UMask 002
Domain *
KeyFile /etc/mail/dkim.key
Selector mail
Mode sv
OversignHeaders From
DomainKeysCompat true


-- no debconf information


--
To UNSUBSCRIBE, email to debian-bugs-...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org

[Scott Kitterman]

On Wednesday, July 15, 2015 12:24:18 AM Cyrille Mescam wrote:
> Package: opendkim
...

> Trying to start the service: service opendkim start

...
> Init: systemd (via /run/systemd/system)
...

You started opendkim with the sysv init interface (which used the old sysv
init script) even though you are running systemd as your init system and a
systemd service file is provided. What happens if you do:

systemctl start opendkim

You may have to clear the failed state first. I think this will do that:

systemctl reset-failed opendkim

Scott K

[Jason Rhinelander]

On Wed, 15 Jul 2015 01:01:41 -0400 Scott Kitterman
<deb...@kitterman.com> wrote:
> On Wednesday, July 15, 2015 12:24:18 AM Cyrille Mescam wrote:
> > Package: opendkim
> ...
> > Trying to start the service: service opendkim start
> ...
> > Init: systemd (via /run/systemd/system)
> ...
>
> You started opendkim with the sysv init interface (which used the old sysv
> init script) even though you are running systemd as your init system and a
> systemd service file is provided. What happens if you do:
>
> systemctl start opendkim
>
> You may have to clear the failed state first. I think this will do that:
>
> systemctl reset-failed opendkim
>

I get exactly the same problem, and the above did not fix it. I found
the problem, however: systemd environment files do *not* support in-line
comments such as:

SOCKET="local:/var/run/opendkim/opendkim.sock" # default

in the original report, or in my case:

SOCKET="inet:12345@localhost" # listen on loopback on port 12345

which is how the examples in /etc/default/opendkim used to be (prefixed
with another # at the beginning of the line). It really isn't obvious
that this change was significant across the upgrade (it looked more like
just cosmetic reformatting), and so I just selected to keep my
currently-installed version.

That broke because systemd doesn't see an inline # as starting a
comment, and so ends up trying to start opendkim by running (in the
original reporter's case):

/usr/sbin/opendkim -x /etc/opendkim.conf -u opendkim -P
/var/run/opendkim/opendkim.pid -p local:/var/run/opendkim/opendkim.sock
"#" default

which is obviously wrong, and hence opendkim fails to start.

So Cyrille can fix this by removing " # default" from the end of the
line in /etc/default/opendkim, and I've fixed my own similarly.

But since these inline comments were the default /etc/default/opendkim
examples in the previous version, this seems like something that is
going to come up for a lot of people when upgrading opendkim on a
systemd-running system, since basically the old /etc/default/opendkim
configuration file won't work with the new package. Is there something
else that can be done to catch and/or fix this on upgrade?


Jason Rhinelander

[Scott Kitterman]

Thanks for the additional troubleshooting and information. I did make the change specifically because the old format didn't work with the service file.

The best thing I've thought is so far is adding a Debian.News entry to warn people on upgrade, but that's certainly not ideal. I'm open to suggestions.

Scott K

[Cyrille Mescam]

Thanks a lot Jason, it works.

A last thing: I also need to change the user owner of dkim signature files. I put the same user than the one running opendkim.

Best regards
Cyrille