3

I've just upgraded a system from 14.04 to 16.04 and among other issues, opendkim no longer starts correctly. I have the following in /var/log/syslog:

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

It appears that opendkim is getting invalid command line arguments. How can I find out what command line is being used, and how it is constructed?

Tracing /etc/init.d/opendkim start does not help, since this just invokes /bin/systemctl --no-pager start opendkim.service. Looking around, I found /lib/systemd/system/opendkim.service which contains the line

ExecStart=/usr/sbin/opendkim -x /etc/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid -p $SOCKET $DAEMON_OPTS

In /etc/default/opendkim, we have SOCKET="inet:8891@localhost" and DAEMON_OPTS left unset. However, if I manually run

/usr/sbin/opendkim -x /etc/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid -p inet:8891@localhost

it succeeds. So apparently that is not the command line which is being used.

Following muru's comment, here is the output of systemctl -l status opendkim.service.

● opendkim.service - DomainKeys Identified Mail (DKIM) Milter
   Loaded: loaded (/lib/systemd/system/opendkim.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Mon 2016-09-19 18:27:59 UTC; 23min ago
     Docs: 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
  Process: 28496 ExecStart=/usr/sbin/opendkim -x /etc/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid -p $SOCKET $DAEMON_OPTS (code=exited, status=64)
  Process: 28488 ExecStartPre=/bin/chown opendkim.opendkim /var/run/opendkim (code=exited, status=0/SUCCESS)
  Process: 28485 ExecStartPre=/bin/mkdir -p /var/run/opendkim (code=exited, status=0/SUCCESS)

Sep 19 18:27:59 aurora opendkim[28496]:         -T timeout          DNS timeout (seconds)
Sep 19 18:27:59 aurora opendkim[28496]:         -u userid           change to specified userid
Sep 19 18:27:59 aurora opendkim[28496]:         -v                  increase verbosity during testing
Sep 19 18:27:59 aurora opendkim[28496]:         -V                  print version number and terminate
Sep 19 18:27:59 aurora opendkim[28496]:         -W                  "why?!" mode (log sign/verify decision logic)
Sep 19 18:27:59 aurora opendkim[28496]:         -x conffile         read configuration from conffile
Sep 19 18:27:59 aurora systemd[1]: opendkim.service: Control process exited, code=exited status=64
Sep 19 18:27:59 aurora systemd[1]: Failed to start DomainKeys Identified Mail (DKIM) Milter.
Sep 19 18:27:59 aurora systemd[1]: opendkim.service: Unit entered failed state.
Sep 19 18:27:59 aurora systemd[1]: opendkim.service: Failed with result 'exit-code'.

The ExecStart line is just as in the file. Is it possible that it is literally passing the string $SOCKET rather than the contents of this variable?

6
  • Does systemctl status opendkim.service shed any light? IIRC it will list the command, but I don't have any system on hand to test. – muru Sep 19 '16 at 18:49
  • @muru: Updated. – Nate Eldredge Sep 19 '16 at 18:54
  • Does the service file say anything about the environment? Does it list /etc/default/opendkim as the EnvironmentFile? – muru Sep 19 '16 at 18:57
  • @muru: Yes, /lib/systemd/system/opendkim.service contains the line EnvironmentFile=-/etc/default/opendkim. I assume the - is normal? – Nate Eldredge Sep 19 '16 at 19:00
  • Yes, the - is normal, it indicates that a missing file is not a problem. – muru Sep 19 '16 at 19:04
4

I figured it out. I tried replacing /usr/sbin/opendkim with a script that logs its command line, and saw that it was getting

-x /etc/opendkim.conf -u opendkim -P /var/run/opendkim/opendkim.pid -p inet:8891@localhost# listen on loopback on port 12345

There was a comment at the end of the line in /etc/default/opendkim that evidently was not getting parsed correctly.

I moved that comment to its own line and now it works.

5
  • 1
    Ah, systemd EnvironmentFile files are not parsed exactly like shell scripts. It is parsed correctly - comment lines should begin with # or ; – muru Sep 19 '16 at 19:18
  • @muru: Yes, and I see now that the newly shipped version of /etc/default/opendkim conforms to that. When I diffed it against my existing version (written for 14.04 with upstart, in which it actually is parsed by the shell AFAIK), I saw that I wanted to keep my setting of SOCKET, and all the other differences were apparently comments, so I just kept my version :-) – Nate Eldredge Sep 19 '16 at 19:21
  • I wouldn't say that that correct way of parsing was unlike shell scripts. like seems more apt. In several shells, # only denotes a comment when it is at the start of a word. The Korn shell, for one, is explicit about this in its manual. The POSIX rules can certainly be read in this way, too. In inet:8891@localhost# it isn't at the start of the word by a long chalk. – JdeBP Sep 19 '16 at 21:40
  • @JdeBP: There was a space before the # in the actual /etc/default/opendkim file. The line was of the form SOCKET="inet:8891@localhost" # comment. I do not know why the space went away when it was passed to opendkim; that's part of the "incorrect parsing" I mentioned. But the # was at the start of a word, though not at the start of the line. – Nate Eldredge Sep 19 '16 at 21:44
  • I can't believe it. For me there were comments without space after # into the /etc/opendkim file 🤔 Now it works like charm! – Sampgun Jan 21 at 20:14

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.