“lost connection after UNKNOWN” (OpenDKIM + postfix receiving emails)

dovecotopendkimpostfixsmtptls

I had a fully working mail server before installingopendkim with TLS with a free StartSSL certificate, that Thunderbird could interface with properly to send/receive email. My distro is Debian 8.

However after installing opendkim I can send validated email, but I can neither receive (see error below) nor does Thunderbird for some reason retrieve email any more after hitting "get mail":

mail.log (last important segments after certificate sharing, email is from a service that you send an email to and it will reply with information on your DKIM/etc, a simple repeatable test for me):

Dec 11 02:11:18 amur postfix/smtpd[2452]: Read 22 chars: EHLO [168.144.32.46]??
Dec 11 02:11:18 amur postfix/smtpd[2452]: Write 180 chars: 250-li211-32.members.linode.com??250-PIP
Dec 11 02:11:18 amur postfix/smtpd[2452]: write to 555895BAD5D0 [555895D2C973] (261 bytes => 261 (0x105))
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0000 17 03 03 01 00 ea fd b3|cf f4 f5 2e 90 95 e2 5f  ........ ......._
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0010 ea 38 64 3a 4d c4 45 aa|45 4e 85 08 48 b9 0e c8  .8d:M.E. EN..H...
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0020 ba 8a 30 62 60 5a 45 d4|ee df 9d 25 de 15 d0 ba  ..0b`ZE. ...%....
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0030 89 09 f4 57 c0 02 42 e3|0e 8c 6c 0e 79 ce 1b 68  ...W..B. ..l.y..h
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0040 20 d3 d1 d9 27 23 d2 bf|58 71 96 23 a9 85 24 9e   ...'#.. Xq.#..$.
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0050 02 14 6b 87 dd aa f8 78|14 62 0f ca e5 cd fd 55  ..k....x .b.....U
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0060 46 05 bc 7b 48 c4 2d 36|54 cf 59 97 b8 b9 f1 5e  F..{H.-6 T.Y....^
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0070 ef 0a 4c 1d 90 82 30 4f|e4 e8 19 19 42 1f 00 1c  ..L...0O ....B...
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0080 76 01 b6 d1 ad fe 62 3e|47 3b e6 bf e1 b9 fc de  v.....b> G;......
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0090 03 4e a4 df e1 36 ca 24|64 8b 54 08 74 98 4f f0  .N...6.$ d.T.t.O.
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00a0 64 7f 90 53 87 2f 95 4e|ee b7 a0 fe d2 03 87 74  d..S./.N .......t
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00b0 7d 47 25 33 80 da bf 20|3b bb d2 a1 76 e0 6f 00  }G%3...  ;...v.o.
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00c0 31 90 48 94 0e 57 a5 1d|fc 69 b5 e6 ed f4 ff ce  1.H..W.. .i......
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00d0 09 74 ea c3 de 92 4b d1|d6 76 d0 10 0a 24 4c bc  .t....K. .v...$L.
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00e0 43 9b 3e e2 32 a0 f5 a4|6a 6d 4b be a0 a7 04 ef  C.>.2... jmK.....
Dec 11 02:11:18 amur postfix/smtpd[2452]: 00f0 5d 84 03 71 b6 a9 af f3|6f 7c 3f 5f c0 a2 7f 7f  ]..q.... o|?_....
Dec 11 02:11:18 amur postfix/smtpd[2452]: 0100 25 d7 5a 56 4e                                   %.ZVN
Dec 11 02:11:18 amur postfix/smtpd[2452]: read from 555895BAD5D0 [555895D24423] (5 bytes => -1 (0xFFFFFFFFFFFFFFFF))
Dec 11 02:11:18 amur postfix/smtpd[2454]: initializing the server-side TLS engine
Dec 11 02:11:18 amur postfix/smtpd[2454]: connect from unlocktheinbox.com[168.144.32.45]
Dec 11 02:11:18 amur postfix/smtpd[2454]: lost connection after UNKNOWN from unlocktheinbox.com[168.144.32.45]
Dec 11 02:11:18 amur postfix/smtpd[2454]: disconnect from unlocktheinbox.com[168.144.32.45]
Dec 11 02:11:18 amur postfix/smtpd[2452]: read from 555895BAD5D0 [555895D24423] (5 bytes => 0 (0x0))
Dec 11 02:11:18 amur postfix/smtpd[2452]: lost connection after EHLO from mail.unlocktheinbox.com[168.144.32.46]
Dec 11 02:11:18 amur postfix/smtpd[2452]: disconnect from mail.unlocktheinbox.com[168.144.32.46]

postfix is running in chroot, and I've attempted to keep the socket for opendkim there.

Here's my postconf -n output:

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
inet_interfaces = all
mailbox_command = procmail -a "$EXTENSION"
mailbox_size_limit = 0
milter_default_action = accept
milter_protocol = 2
mydestination = li211-32.members.linode.com, localhost.members.linode.com, localhost
myhostname = li211-32.members.linode.com
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
myorigin = /etc/mailname
non_smtpd_milters = $smtpd_milters
queue_directory = /var/spool/postfix
readme_directory = no
recipient_delimiter = +
relayhost =
smtp_tls_CAfile = /etc/postfix/ssl/ca-bundle.crt
smtp_tls_cert_file = /etc/nginx/conf.d/ssl-unified.crt
smtp_tls_key_file = /etc/nginx/conf.d/ssl.key
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_delay_reject = yes
smtpd_milters = unix:/var/run/opendkim/opendkim.sock
smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks, reject_unauth_destination
smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain = <mysite.com>
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_tls_security_options = $smtpd_sasl_security_options
smtpd_sasl_type = dovecot
smtpd_sender_login_maps = mysql:/etc/postfix/mysql-virtual-mailbox-maps.cf
smtpd_tls_CAfile = /etc/postfix/ssl/ca-bundle.crt
smtpd_tls_ask_ccert = yes
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/nginx/conf.d/ssl-unified.crt
smtpd_tls_key_file = /etc/nginx/conf.d/ssl.key
smtpd_tls_loglevel = 4
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
virtual_alias_maps = mysql:/etc/postfix/mysql-virtual-alias-maps.cf
virtual_mailbox_domains = mysql:/etc/postfix/mysql-virtual-mailbox-domains.cf
virtual_mailbox_maps = mysql:/etc/postfix/mysql-virtual-mailbox-maps.cf
virtual_transport = lmtp:unix:private/dovecot-lmtp

To be complete, opendkim.conf and default/opendkim

Syslog                  yes
UMask                  0002
UserID                 opendkim:opendkim #within group of postfix
ExternalIgnoreList      refile:/etc/opendkim/TrustedHosts
InternalHosts           refile:/etc/opendkim/TrustedHosts
KeyTable                refile:/etc/opendkim/KeyTable
SigningTable            refile:/etc/opendkim/SigningTable

AutoRestart             yes
AutoRestartRate         10/1h
Background              yes
Canonicalization        relaxed/relaxed
DNSTimeout              5
Mode                    sv
SignatureAlgorithm      rsa-sha256
SubDomains              no
X-Header                no
PidFile                 local:/var/spool/postfix/var/run/opendkim/opendkim.pid
Statistics              /var/log/dkim-filter/dkim-stats

and

SOCKET="local:/var/spool/postfix/var/run/opendkim/opendkim.sock"

both the chroot and nonchroot opendkim.sock/pid are owned by opendkim and with appropriate permissions.

Dozens of hours to get to this point…

Being dkim related, I presume it's some funky error… but no guide I can replicate any other issue (the second I get the .sock file to be read and found with the right permissions, it starts the no after UNKNOWN drop again.)

Is that maybe because DKIM's failure simple is not interpretable by postfix, and that is what the unknown is about? any tips?

How do I debug DKIM perhaps?

(I'm also using port 587, I believe port 25 is not reachable for some reason. even though some time earlier it was available.)

Best Answer

Note that port 25 HAS TO be open: communication between servers is done using this port. Check firewalls, routers, nmap and netstat to figure out why it's not accessible. Port 587 (submission) is only for authenticated users, so they can send their mails through the server.