0

I for the life of me cannot get OpenDKIM to work correctly. I can send and receive messages just fine with postfix and roundcube. I have tried tons of things to get this working. At this point, I am not getting any errors, but OpenDKIM is not signing mail. I have tried everything I can find on this site already.

Here is my main.cf:

# See /usr/share/postfix/main.cf.dist for a commented, more complete version

# Debian specific:  Specifying a file name will cause the first
# line of that file to be used as the name.  The Debian default
# is /etc/mailname.
#myorigin = /etc/mailname

smtpd_banner = $myhostname ESMTP $mail_name (Raspbian) This is not an open relay.
biff = no

# appending .domain is the MUA's job.
append_dot_mydomain = no

# Uncomment the next line to generate "delayed mail" warnings
#delay_warning_time = 4h

readme_directory = no

policyd-spf_time_limit = 3600

milter_default_action = accept
milter_protocol = 6
smtpd_milters = unix:/var/run/opendkim/opendkim.sock
non-smtpd_milters = unix:/var/run/opendkim/opendkim.sock

# TLS parameters
smtpd_tls_cert_file = /root/fullchain.pem
smtpd_tls_key_file = /root/privkey.pem
smtpd_use_tls = yes
smtpd_tls_auth_only = yes
smtpd_tls_loglevel = 2

smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_sasl_auth_enable = yes


smtpd_relay_restrictions =
  # subject even authenticated users and trusted networks
  # to the policy check
  #check_policy_service inet:127.0.0.1:10031
  permit_mynetworks
  reject_unknown_sender_domain
  permit_sasl_authenticated
  defer_unauth_destination

smtpd_recipient_restrictions =
  permit_mynetworks
  permit_sasl_authenticated
  check_policy_service unix:private/policyd-spf,
  # we exclude our networks and SASL authenticated users
  # from all further checks.
  # since I don't know if the policy service is relevant
  # for unauthenticated mail, I commented it out here
  # check_policy_service inet:127.0.0.1:10031
  warn_if_reject reject_non_fqdn_hostname
  warn_if_reject reject_non_fqdn_sender
  reject_invalid_hostname
  reject_unknown_sender_domain

smtpd_data_restrictions = reject_unauth_pipelining

# See /usr/share/doc/postfix/TLS_README.gz in the postfix-doc package for
# information on enabling SSL in the smtp client.

myhostname = mail.smbecker.tk
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
myorigin = /etc/mailname
mydestination = localhost
relayhost =
mynetworks = 10.0.0.0/8 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all

#Handing off local delivery to Dovecot's LMTP, and telling it where to store mail
virtual_transport = lmtp:unix:private/dovecot-lmtp

#Virtual domains, users, and aliases
virtual_mailbox_domains = mysql:/etc/postfix/mysql-virtual-mailbox-domains.cf
virtual_mailbox_maps = mysql:/etc/postfix/mysql-virtual-mailbox-maps.cf
virtual_alias_maps = mysql:/etc/postfix/mysql-virtual-alias-maps.cf

inet_protocols = ipv4

Here is my opendkim.conf:

# This is a basic configuration that can easily be adapted to suit a standard
# installation. For more advanced options, see opendkim.conf(5) and/or
# /usr/share/doc/opendkim/examples/opendkim.conf.sample.

# Log to syslog
Syslog                  yes
# Required to use local socket with MTAs that access the socket as a non-
# privileged user (e.g. Postfix)
UMask                   002

# Map domains in From addresses to keys used to sign messages
KeyTable                /etc/opendkim/key.table
SigningTable            /etc/opendkim/signing.table

# Hosts to ignore when verifying signatures
ExternalIgnoreList      /etc/opendkim/trusted.hosts
InternalHosts           /etc/opendkim/trusted.hosts


# Sign for example.com with key in /etc/dkimkeys/dkim.key using
# selector '2007' (e.g. 2007._domainkey.example.com)
#Domain                 example.com
#KeyFile                /etc/dkimkeys/dkim.key
#Selector               2007

# Commonly-used options; the commented-out versions show the defaults.
#Canonicalization       simple
Mode                    sv
SubDomains              no

AutoRestart             yes
AutoRestartRate         10/1m
Background              yes
DNSTimeout              5
SignatureAlgorithm      rsa-sha256

# Socket smtp://localhost
#
# ##  Socket socketspec
# ##
# ##  Names the socket where this filter should listen for milter connections
# ##  from the MTA.  Required.  Should be in one of these forms:
# ##
# ##  inet:port@address           to listen on a specific interface
# ##  inet:port                   to listen on all interfaces
# ##  local:/path/to/socket       to listen on a UNIX domain socket
#
#Socket                  inet:8892@localhost
Socket                  local:/var/spool/postfix/var/run/opendkim/opendkim.sock

##  PidFile filename
###      default (none)
###
###  Name of the file where the filter should write its pid before beginning
###  normal operations.
#
PidFile               /var/spool/postfix/var/run/opendkim/opendkim.pid


# Always oversign From (sign using actual From and a null From to prevent
# malicious signatures header fields (From and/or others) between the signer
# and the verifier.  From is oversigned by default in the Debian pacakge
# because it is often the identity key used by reputation systems and thus
# somewhat security sensitive.
OversignHeaders         From

##  ResolverConfiguration filename
##      default (none)
##
##  Specifies a configuration file to be passed to the Unbound library that
##  performs DNS queries applying the DNSSEC protocol.  See the Unbound
##  documentation at http://unbound.net for the expected content of this file.
##  The results of using this and the TrustAnchorFile setting at the same
##  time are undefined.
##  In Debian, /etc/unbound/unbound.conf is shipped as part of the Suggested
##  unbound package

# ResolverConfiguration     /etc/unbound/unbound.conf

##  TrustAnchorFile filename
##      default (none)
##
## Specifies a file from which trust anchor data should be read when doing
## DNS queries and applying the DNSSEC protocol.  See the Unbound documentation
## at http://unbound.net for the expected format of this file.

TrustAnchorFile       /usr/share/dns/root.key

##  Userid userid
###      default (none)
###
###  Change to user "userid" before starting normal operation?  May include
###  a group ID as well, separated from the userid by a colon.
#
UserID                opendkim

Here is my /etc/systemd/system/multi-user.target.wants/opendkim.service (I had to edit in order to get opendkim.sock and opendkim.pid to even show up and be able to get rid of the postfix errors)

[Unit]
Description=OpenDKIM 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

[Service]
Type=forking
PIDFile=/var/spool/postfix/var/run/opendkim/opendkim.pid
UMask=0007
ExecStart=/usr/sbin/opendkim -P /var/spool/postfix/var/run/opendkim/opendkim.pid -p local:/var/spool/postfix/var/run/opendkim/opendkim.sock
Restart=on-failure
ExecReload=/bin/kill -USR1 $MAINPID

[Install]
WantedBy=multi-user.target

key.table:

smbecker.tk smbecker.tk:YYYYMM:/etc/opendkim/keys/smbecker.tk.private

signing.table:

*@smbecker.tk smbecker.tk

I have done tons of editing and checking owners and permissions to get to even this point getting rid of milter connection errors (not found and refused). The opendkim.pid changes to root ownership everytime opendkim is restarted, but even if I do a chown and chmod to give it to opendkim with a 0777, I still get same result. Messages don't get signed:

DKIM Information:
DKIM Signature

This message does not contain a DKIM Signature

I am using Raspian-Stretch. I have Postfix, Dovecot, Roundcube all working and am sending emails via Roundcube. All outgoing email should have DKIM signatures, but don't.

Requested mail.log:

Jan 10 18:35:34 raspberrypi postfix[23526]: Postfix is running with backwards-compatible default settings
Jan 10 18:35:34 raspberrypi postfix[23526]: See http://www.postfix.org/COMPATIBILITY_README.html for details
Jan 10 18:35:34 raspberrypi postfix[23526]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload"
Jan 10 18:35:34 raspberrypi postfix/postfix-script[23533]: stopping the Postfix mail system
Jan 10 18:35:34 raspberrypi postfix/master[23241]: terminating on signal 15
Jan 10 18:35:35 raspberrypi postfix[23602]: Postfix is running with backwards-compatible default settings
Jan 10 18:35:35 raspberrypi postfix[23602]: See http://www.postfix.org/COMPATIBILITY_README.html for details
Jan 10 18:35:35 raspberrypi postfix[23602]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload"
Jan 10 18:35:37 raspberrypi postfix/postfix-script[23709]: starting the Postfix mail system
Jan 10 18:35:37 raspberrypi postfix/master[23711]: daemon started -- version 3.1.8, configuration /etc/postfix
Jan 10 18:35:44 raspberrypi postfix/smtpd[23721]: initializing the server-side TLS engine
Jan 10 18:35:44 raspberrypi postfix/smtpd[23721]: connect from unknown[10.100.0.3]
Jan 10 18:35:44 raspberrypi postfix/smtpd[23721]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 18:35:44 raspberrypi postfix/smtpd[23721]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 18:35:57 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23761, TLS, session=<BPvl4CN/TKcKZGQB>
Jan 10 18:35:57 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=32 out=479
Jan 10 18:35:57 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23763, TLS, session=<+Ezu4CN/TqcKZGQB>
Jan 10 18:35:58 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=44 out=675
Jan 10 18:36:14 raspberrypi postfix/smtpd[23721]: connect from unknown[10.100.0.3]
Jan 10 18:36:14 raspberrypi postfix/smtpd[23721]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 18:36:14 raspberrypi postfix/smtpd[23721]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 18:36:15 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Connection closed in=133 out=1271
Jan 10 18:36:16 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23767, TLS, session=<D+YD4iN/IrcKZGQB>
Jan 10 18:36:21 raspberrypi postfix/smtpd[23768]: initializing the server-side TLS engine
Jan 10 18:36:21 raspberrypi postfix/smtpd[23768]: connect from unknown[10.100.100.1]
Jan 10 18:36:21 raspberrypi postfix/smtpd[23768]: 4630CDDC30: client=unknown[10.100.100.1]
Jan 10 18:36:21 raspberrypi postfix/cleanup[23770]: 4630CDDC30: message-id=<f1442883c4d8700a241ca81e77bc9b84@smbecker.tk>
Jan 10 18:36:21 raspberrypi postfix/qmgr[23713]: 4630CDDC30: from=<smbecker3673@smbecker.tk>, size=492, nrcpt=1 (queue active)
Jan 10 18:36:21 raspberrypi postfix/smtpd[23768]: disconnect from unknown[10.100.100.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Jan 10 18:36:21 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23773, TLS, session=<4MZZ4iN/WqcKZGQB>
Jan 10 18:36:21 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=351 out=635
Jan 10 18:36:21 raspberrypi postfix/smtp[23771]: 4630CDDC30: to=<WTnCkOoN6Z8l0S@dkimvalidator.com>, relay=31045262.in1.mandrillapp.com[54.245.105.162]:25, delay=0.73, delays=0.13/0.05/0.37/0.18, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as CBAA421FF4)
Jan 10 18:36:21 raspberrypi postfix/qmgr[23713]: 4630CDDC30: removed
Jan 10 18:36:22 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23775, TLS, session=<5Wtr4iN/XqcKZGQB>
Jan 10 18:36:23 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=44 out=675
Jan 10 18:36:24 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23778, TLS, session=<0op+4iN/YKcKZGQB>
Jan 10 18:36:24 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=120 out=850
Jan 10 18:36:24 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=23779, TLS, session=<EDaC4iN/YqcKZGQB>
Jan 10 18:36:24 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=292 out=2438
Jan 10 18:36:44 raspberrypi postfix/smtpd[23721]: connect from unknown[10.100.0.3]
Jan 10 18:36:44 raspberrypi postfix/smtpd[23721]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 18:36:44 raspberrypi postfix/smtpd[23721]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 18:37:14 raspberrypi postfix/smtpd[23721]: connect from unknown[10.100.0.3]
Jan 10 18:37:14 raspberrypi postfix/smtpd[23721]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 18:37:14 raspberrypi postfix/smtpd[23721]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1

The connections form 10.100.0.3 is a Mikrotik Dude Server that just probes services and devices so that can be ignored. As you can see there is no errors in the log currently, but I don't see anything regarding DKIM either.

Mail logs with DKIM restart in it after changing it back:

Jan 10 20:28:49 raspberrypi postfix[25666]: Postfix is running with backwards-compatible default settings
Jan 10 20:28:49 raspberrypi postfix[25666]: See http://www.postfix.org/COMPATIBILITY_README.html for details
Jan 10 20:28:49 raspberrypi postfix[25666]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload"
Jan 10 20:28:49 raspberrypi postfix/postfix-script[25672]: stopping the Postfix mail system
Jan 10 20:28:49 raspberrypi postfix/master[25566]: terminating on signal 15
Jan 10 20:28:50 raspberrypi postfix[25741]: Postfix is running with backwards-compatible default settings
Jan 10 20:28:50 raspberrypi postfix[25741]: See http://www.postfix.org/COMPATIBILITY_README.html for details
Jan 10 20:28:50 raspberrypi postfix[25741]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload"
Jan 10 20:28:52 raspberrypi postfix/postfix-script[25849]: starting the Postfix mail system
Jan 10 20:28:52 raspberrypi postfix/master[25851]: daemon started -- version 3.1.8, configuration /etc/postfix
Jan 10 20:29:14 raspberrypi postfix/smtpd[25864]: initializing the server-side TLS engine
Jan 10 20:29:14 raspberrypi postfix/smtpd[25864]: connect from unknown[10.100.0.3]
Jan 10 20:29:14 raspberrypi postfix/smtpd[25864]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 20:29:14 raspberrypi postfix/smtpd[25864]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 20:29:24 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=25869, TLS, session=<J66gdiV/bKkKZGQB>
Jan 10 20:29:24 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=90 out=896
Jan 10 20:29:44 raspberrypi postfix/smtpd[25864]: connect from unknown[10.100.0.3]
Jan 10 20:29:44 raspberrypi postfix/smtpd[25864]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 20:29:44 raspberrypi postfix/smtpd[25864]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 20:30:14 raspberrypi postfix/smtpd[25864]: connect from unknown[10.100.0.3]
Jan 10 20:30:14 raspberrypi postfix/smtpd[25864]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 20:30:14 raspberrypi postfix/smtpd[25864]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1
Jan 10 20:30:24 raspberrypi dovecot: imap-login: Login: user=<smbecker3673@smbecker.tk>, method=PLAIN, rip=10.100.100.1, lip=10.100.0.150, mpid=25925, TLS, session=<dlcxeiV/cKkKZGQB>
Jan 10 20:30:24 raspberrypi dovecot: imap(smbecker3673@smbecker.tk): Logged out in=90 out=896
Jan 10 20:30:29 raspberrypi opendkim[25654]: OpenDKIM Filter: mi_stop=1
Jan 10 20:30:29 raspberrypi opendkim[25654]: OpenDKIM Filter v2.11.0 terminating with status 0, errno = 0
Jan 10 20:30:29 raspberrypi opendkim[25934]: OpenDKIM Filter v2.11.0 starting (args: -P /var/spool/postfix/var/run/opendkim/opendkim.pid -p local:/var/spool/postfix/var/run/opendkim/opendkim.sock)
Jan 10 20:30:44 raspberrypi postfix/smtpd[25864]: connect from unknown[10.100.0.3]
Jan 10 20:30:44 raspberrypi postfix/smtpd[25864]: lost connection after EHLO from unknown[10.100.0.3]
Jan 10 20:30:44 raspberrypi postfix/smtpd[25864]: disconnect from unknown[10.100.0.3] ehlo=1 commands=1

Also ps -aux | grep opendkim

opendkim 25933  0.0  0.3  14884  2976 ?        Ss   20:30   0:00 /usr/sbin/opendkim -P /var/spool/postfix/var/run/opendkim/opendkim.pid -p local:/var/spool/postfix/var/run/opendkim/opendkim.sock
opendkim 25934  0.0  0.6  59044  5804 ?        Sl   20:30   0:00 /usr/sbin/opendkim -P /var/spool/postfix/var/run/opendkim/opendkim.pid -p local:/var/spool/postfix/var/run/opendkim/opendkim.sock
root     26283  0.0  0.0   4376   576 pts/0    S+   20:52   0:00 grep opendkim

TCPDUMP when sending email:

listening on lo, link-type EN10MB (Ethernet), capture size 262144 bytes
17:52:44.828861 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [S], seq 3182105441, win 43690, options [mss 65495,sackOK,TS val 3741998642 ecr 0,nop,wscale 7], length 0
17:52:44.828938 IP 127.0.0.1.8892 > 127.0.0.1.33124: Flags [S.], seq 435085374, ack 3182105442, win 43690, options [mss 65495,sackOK,TS val 3741998642 ecr 3741998642,nop,wscale 7], length 0
17:52:44.829036 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [.], ack 1, win 342, options [nop,nop,TS val 3741998642 ecr 3741998642], length 0
17:52:44.829290 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [P.], seq 1:18, ack 1, win 342, options [nop,nop,TS val 3741998642 ecr 3741998642], length 17
17:52:44.829596 IP 127.0.0.1.8892 > 127.0.0.1.33124: Flags [P.], seq 1:18, ack 18, win 342, options [nop,nop,TS val 3741998642 ecr 3741998642], length 17
17:52:44.829749 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [P.], seq 18:122, ack 18, win 342, options [nop,nop,TS val 3741998643 ecr 3741998642], length 104
17:52:44.829912 IP 127.0.0.1.8892 > 127.0.0.1.33124: Flags [P.], seq 18:23, ack 122, win 342, options [nop,nop,TS val 3741998643 ecr 3741998643], length 5
17:52:44.831489 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [P.], seq 122:138, ack 23, win 342, options [nop,nop,TS val 3741998644 ecr 3741998643], length 16
17:52:44.831571 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [F.], seq 138, ack 23, win 342, options [nop,nop,TS val 3741998644 ecr 3741998643], length 0
17:52:44.832194 IP 127.0.0.1.8892 > 127.0.0.1.33124: Flags [F.], seq 23, ack 139, win 342, options [nop,nop,TS val 3741998645 ecr 3741998644], length 0
17:52:44.832271 IP 127.0.0.1.33124 > 127.0.0.1.8892: Flags [.], ack 24, win 342, options [nop,nop,TS val 3741998645 ecr 3741998645], length 0
17:53:13.817007 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [S], seq 2310383764, win 43690, options [mss 65495,sackOK,TS val 3742027630 ecr 0,nop,wscale 7], length 0
17:53:13.817082 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [S.], seq 2557593622, ack 2310383765, win 43690, options [mss 65495,sackOK,TS val 3742027630 ecr 3742027630,nop,wscale 7], length 0
17:53:13.817156 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 1, win 342, options [nop,nop,TS val 3742027630 ecr 3742027630], length 0
17:53:13.817363 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1:18, ack 1, win 342, options [nop,nop,TS val 3742027630 ecr 3742027630], length 17
17:53:13.817401 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [.], ack 18, win 342, options [nop,nop,TS val 3742027630 ecr 3742027630], length 0
17:53:13.817704 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 1:18, ack 18, win 342, options [nop,nop,TS val 3742027631 ecr 3742027630], length 17
17:53:13.818019 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 18:23, ack 124, win 342, options [nop,nop,TS val 3742027631 ecr 3742027631], length 5
17:53:13.860290 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 23, win 342, options [nop,nop,TS val 3742027673 ecr 3742027631], length 0
17:53:14.068860 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 124:407, ack 23, win 342, options [nop,nop,TS val 3742027882 ecr 3742027631], length 283
17:53:14.069221 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 23:28, ack 407, win 350, options [nop,nop,TS val 3742027882 ecr 3742027882], length 5
17:53:14.069275 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 28, win 342, options [nop,nop,TS val 3742027882 ecr 3742027882], length 0
17:53:14.156900 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 407:519, ack 28, win 342, options [nop,nop,TS val 3742027970 ecr 3742027882], length 112
17:53:14.157128 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 28:33, ack 519, win 350, options [nop,nop,TS val 3742027970 ecr 3742027970], length 5
17:53:14.157166 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 33, win 342, options [nop,nop,TS val 3742027970 ecr 3742027970], length 0
17:53:14.203842 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 519:538, ack 33, win 342, options [nop,nop,TS val 3742028017 ecr 3742027970], length 19
17:53:14.250297 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [.], ack 538, win 350, options [nop,nop,TS val 3742028063 ecr 3742028017], length 0
17:53:14.250369 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 538:595, ack 33, win 342, options [nop,nop,TS val 3742028063 ecr 3742028063], length 57
17:53:14.250405 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [.], ack 595, win 350, options [nop,nop,TS val 3742028063 ecr 3742028063], length 0
17:53:14.250693 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 33:38, ack 595, win 350, options [nop,nop,TS val 3742028064 ecr 3742028063], length 5
17:53:14.250722 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 38, win 342, options [nop,nop,TS val 3742028064 ecr 3742028064], length 0
17:53:14.250877 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 595:648, ack 38, win 342, options [nop,nop,TS val 3742028064 ecr 3742028064], length 53
17:53:14.251112 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 648:686, ack 43, win 342, options [nop,nop,TS val 3742028064 ecr 3742028064], length 38
17:53:14.251234 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 43:48, ack 686, win 350, options [nop,nop,TS val 3742028064 ecr 3742028064], length 5
17:53:14.251334 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 686:748, ack 48, win 342, options [nop,nop,TS val 3742028064 ecr 3742028064], length 62
17:53:14.251458 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 48:53, ack 748, win 350, options [nop,nop,TS val 3742028064 ecr 3742028064], length 5
17:53:14.251562 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 748:830, ack 53, win 342, options [nop,nop,TS val 3742028064 ecr 3742028064], length 82
17:53:14.251688 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 53:58, ack 830, win 350, options [nop,nop,TS val 3742028065 ecr 3742028064], length 5
17:53:14.251784 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 830:872, ack 58, win 342, options [nop,nop,TS val 3742028065 ecr 3742028065], length 42
17:53:14.251905 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 58:63, ack 872, win 350, options [nop,nop,TS val 3742028065 ecr 3742028065], length 5
17:53:14.252010 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 872:987, ack 63, win 342, options [nop,nop,TS val 3742028065 ecr 3742028065], length 115
17:53:14.252137 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 63:68, ack 987, win 350, options [nop,nop,TS val 3742028065 ecr 3742028065], length 5
17:53:14.252236 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 987:1044, ack 68, win 342, options [nop,nop,TS val 3742028065 ecr 3742028065], length 57
17:53:14.252577 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 73:78, ack 1115, win 350, options [nop,nop,TS val 3742028066 ecr 3742028065], length 5
17:53:14.252680 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1115:1163, ack 78, win 342, options [nop,nop,TS val 3742028066 ecr 3742028066], length 48
17:53:14.252803 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 78:83, ack 1163, win 350, options [nop,nop,TS val 3742028066 ecr 3742028066], length 5
17:53:14.252903 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1163:1251, ack 83, win 342, options [nop,nop,TS val 3742028066 ecr 3742028066], length 88
17:53:14.253026 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 83:88, ack 1251, win 350, options [nop,nop,TS val 3742028066 ecr 3742028066], length 5
17:53:14.253143 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1251:1301, ack 88, win 342, options [nop,nop,TS val 3742028066 ecr 3742028066], length 50
17:53:14.253264 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 88:93, ack 1301, win 350, options [nop,nop,TS val 3742028066 ecr 3742028066], length 5
17:53:14.253351 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1301:1325, ack 93, win 342, options [nop,nop,TS val 3742028066 ecr 3742028066], length 24
17:53:14.264091 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 93:98, ack 1325, win 350, options [nop,nop,TS val 3742028077 ecr 3742028066], length 5
17:53:14.264434 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 1325:4540, ack 98, win 342, options [nop,nop,TS val 3742028077 ecr 3742028077], length 3215
17:53:14.264532 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [.], ack 4540, win 1373, options [nop,nop,TS val 3742028077 ecr 3742028077], length 0
17:53:14.264652 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 98:103, ack 4540, win 1373, options [nop,nop,TS val 3742028078 ecr 3742028077], length 5
17:53:14.264734 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [P.], seq 4540:4564, ack 103, win 342, options [nop,nop,TS val 3742028078 ecr 3742028078], length 24
17:53:14.266378 IP 127.0.0.1.8892 > 127.0.0.1.33126: Flags [P.], seq 103:108, ack 4564, win 1373, options [nop,nop,TS val 3742028079 ecr 3742028078], length 5
17:53:14.310331 IP 127.0.0.1.33126 > 127.0.0.1.8892: Flags [.], ack 108, win 342, options [nop,nop,TS val 3742028123 ecr 3742028079], length 0

^C
75 packets captured
164 packets received by filter
9 packets dropped by kernel

2 Answers2

2

Are you postfix is chrooted ? If not the socket paths don't match. Maybe try on a local tcp port, usually opendkim setup for 8891, so change smtpd_milters = inet:127.0.0.1:8891 non_smtpd_milters = inet:127.0.0.1:8891 in postfix's main.cf, and Socket inet:8891@127.0.0.1 in opendkim.conf.

That way you can tcpdump local interface and see if there is any communication between postfix&opendkim. Bit weird since in logs you should see something from opendkim if he gets the mail. Obviously depends how syslog configured. If you restart opendkim, do you see anything in this log ( should log a line about starting ), maybe opendkim logs are in another file.

Sandor Marton
  • 1,544
  • 9
  • 12
  • I will try this. I do get a log when restarting opendkim, that's it though. I am pretty sure I could only get postfix to work with chroot. Before switching everything on doing to the chroot path, I had errors on postfix milter saying it couldn't find the files so it is looking in the chroot location I have set since those errors went away. – Shane Becker Jan 11 '19 at 02:10
  • That causes a warning: connect to Milter service inet:127.0.0.1:8891: Connection refused – Shane Becker Jan 11 '19 at 02:24
  • In the log from the question i don't see any dkim lines, so that's why i said that maybe is another file. – Sandor Marton Jan 11 '19 at 02:27
  • Did you restart opendkim? If yes, then seems there is problem at start, maybe a syntax error in config, please check dkim log – Sandor Marton Jan 11 '19 at 02:28
  • Updated question with logs that contain opendkim restart which shows no errors – Shane Becker Jan 11 '19 at 02:48
  • Do you the tcp port open with netstat -tnl or ss -tnl ? If not, maybe you added the 'Socket... ' line to opendkim.conf, and you didn't replace the old Socket line. So opendkim is ignoring the second Socket line – Sandor Marton Jan 11 '19 at 03:14
  • I was able to get it to run on the TCP port. I found somewhere opendkim on Debian Stretch has an issue with ignoring the opendkim.conf. I also needed to change my /etc/systemd/system/multi-user.target.wants/opendkim.service. Still gives me the same result of not signing messages. It's like it's running but is ignoring all configurations or something. – Shane Becker Jan 11 '19 at 13:50
  • It does create a log entry for incoming messages so those are being piped to opendkim, just not outgoing ones. Maybe something with postfix is not set correct? – Shane Becker Jan 11 '19 at 14:03
  • As long you have that 4 milter line in main.cf, should pass the mail to opendkim. but try to tcpdump , run tcpdump -n -i lo port 8891 , then send a mail and see if there is any traffic in tcpdump output ( let's say in the next 10 sec , or before the mail is delivered ) – Sandor Marton Jan 11 '19 at 18:17
  • I get a bunch with that when sending an email. Edited the question to include it. – Shane Becker Jan 11 '19 at 23:54
1

With the help of Sandor Marton crossing stuff off the potential issues list. I read somewhere that refile: was not required in here and fixed someone elses issue:

SigningTable            /etc/opendkim/signing.table

This however was not the case for me. I needed to put refile: back into the opendkim.conf for the line regarding signing table. Here is the new entry that made opendkim start to actually try signing outgoing emails.

SigningTable            refile:/etc/opendkim/signing.table

Then I started seeing permission errors for the keys in the mail log which I fixed and everything is now working.