Hi Viktor,
thank you for the script I will run it asap on the server.
Meanwhile I think the problem is the following:
I'm running a smtp_proxy_filter on localhost:10024 as described in
http://postfix.cs.utah.edu/SMTPD_PROXY_README.html
smtp inet n - n - - smtpd
-o smtpd_proxy_filter=localhost:10024
-o smtpd_proxy_options=speed_adjust
-o smtp_send_xforward_command=yes
and it seems that smtp is trying to initiate a tls handshake with this
proxy which does not support tls, leading to the timeout of 300s. Is
there an option to prevent the attempt to initiate a tls
I've set in main.cf:
smtp_use_tls = yes
smtpd_use_tls = yes
smtpd_tls_security_level = may
smtp_tls_security_level = may
smtp_tls_loglevel = 3
smtpd_tls_loglevel = 3
and here is the log:
mail() on [/data/development/phpmail/mail.php:9]: To:
dietrich.streif...@googlemail.com -- Headers: From: nore...@zzzz.de
Reply-To: s...@zzzz.de X-Mailer: PHP/5.4.16
Mar 3 09:26:47 node1 postfix/pickup[20765]: 5392C35E3D9: uid=0 from=<root>
Mar 3 09:26:47 node1 postsrsd[29345]: srs_forward: <r...@xxxx.yyyy.de>
rewritten as <SRS0=ePVJ=O7=xxxx.yyyy.de=r...@yyyy.de>
Mar 3 09:26:47 node1 postfix/cleanup[29344]: 5392C35E3D9:
message-id=<20160303082647.5392c35e...@xxxx.yyyy.de>
Mar 3 09:26:47 node1 opendkim[11665]: 5392C35E3D9: DKIM-Signature field
added (s=default, d=zzzz.de)
Mar 3 09:26:47 node1 postfix/qmgr[20766]: 5392C35E3D9:
from=<srs0=epvj=o7=xxxx.yyyy.de=r...@yyyy.de>, size=449, nrcpt=1 (queue
active)
Mar 3 09:26:47 node1 postfix/smtp[29350]: initializing the client-side
TLS engine
Mar 3 09:26:47 node1 postfix/smtpd[29351]: initializing the server-side
TLS engine
Mar 3 09:26:47 node1 postfix/smtpd[29351]: connect from unknown[127.0.0.1]
Mar 3 09:26:47 node1 dovecot: auth: Debug: Loading modules from
directory: /usr/lib64/dovecot/auth
Mar 3 09:26:47 node1 dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
Mar 3 09:26:47 node1 dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_sqlite.so
Mar 3 09:26:47 node1 dovecot: auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
Mar 3 09:26:47 node1 dovecot: auth: Debug: passwd-file
/etc/dovecot/master-users: Read 1 users in 0 secs
Mar 3 09:26:47 node1 dovecot: auth: Debug: auth client connected (pid=0)
Mar 3 09:26:47 node1 postfix/smtpd[29351]: setting up TLS connection
from unknown[127.0.0.1]
Mar 3 09:26:47 node1 postfix/smtp[29350]: setting up TLS connection to
localhost[127.0.0.1]:10024
Mar 3 09:26:47 node1 postfix/smtpd[29351]: unknown[127.0.0.1]: TLS
cipher list
"aNULL:-aNULL:ALL:+RC4:@STRENGTH:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!MD5:!PSK:!aECDH:!EDH-DSS-DES-CBC3-SHA:!EDH-RSA-DES-CDC3-SHA:!KRB5-DE5:!CBC3-SHA"
Mar 3 09:26:47 node1 postfix/smtp[29350]: localhost[127.0.0.1]:10024:
TLS cipher list "aNULL:-aNULL:ALL:+RC4:@STRENGTH"
Mar 3 09:26:47 node1 postfix/smtp[29350]: looking for session
smtp-proxy:127.0.0.1:10024:xxxx.yyyy.de&p=1&c=aNULL:-aNULL:ALL:+RC4:@STRENGTH&l=268439647
in smtp cache
Mar 3 09:26:47 node1 postfix/tlsmgr[21697]: lookup smtp session
id=smtp-proxy:127.0.0.1:10024:xxxx.yyyy.de&p=1&c=aNULL:-aNULL:ALL:+RC4:@STRENGTH&l=268439647
Mar 3 09:26:47 node1 postfix/smtpd[29351]: SSL_accept:before/accept
initialization
Mar 3 09:26:47 node1 postfix/smtpd[29351]: read from 7F9653755DD0
[7F965375B3B0] (11 bytes => -1 (0xFFFFFFFFFFFFFFFF))
Mar 3 09:26:47 node1 postfix/smtp[29350]: SSL_connect:before/connect
initialization
Mar 3 09:26:47 node1 postfix/smtp[29350]: write to 7FAD076983A0
[7FAD07699B70] (299 bytes => 299 (0x12B))
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0000 16 03 01 01 26 01 00
01|22 03 03 56 d7 f5 47 a8 ....&... "..V..G.
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0010 db 3c f0 af 6b f0 4c
3d|07 58 36 71 f7 52 fb a5 .<..k.L= .X6q.R..
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0020 71 ba 43 a9 81 85 87
62|cf b0 e1 00 00 b8 c0 19 q.C....b ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0030 00 a7 00 6d 00 3a 00
89|c0 30 c0 2c c0 28 c0 24 ...m.:.. .0.,.(.$
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0040 c0 14 c0 0a 00 a3 00
9f|00 6b 00 6a 00 39 00 38 ........ .k.j.9.8
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0050 00 88 00 87 c0 32 c0
2e|c0 2a c0 26 c0 0f c0 05 .....2.. .*.&....
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0060 00 9d 00 3d 00 35 00
84|c0 18 00 a6 00 6c 00 34 ...=.5.. .....l.4
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0070 c0 17 00 9b 00 46 00
1b|c0 2f c0 2b c0 27 c0 23 .....F.. ./.+.'.#
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0080 c0 13 c0 09 00 a2 00
9e|00 67 00 40 00 33 00 32 ........ .g.@.3.2
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0090 c0 12 c0 08 00 9a 00
99|00 45 00 44 00 16 00 13 ........ .E.D....
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00a0 c0 31 c0 2d c0 29 c0
25|c0 0e c0 04 c0 0d c0 03 .1.-.).% ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00b0 00 9c 00 3c 00 2f 00
96|00 41 00 0a 00 07 c0 16 ...<./.. .A......
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00c0 00 18 c0 11 c0 07 c0
0c|c0 02 00 05 00 04 00 1a ........ ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00d0 00 15 00 12 00 09 00
19|00 14 00 11 00 08 00 06 ........ ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00e0 00 17 00 03 00 ff 01
00|00 41 00 0b 00 04 03 00 ........ .A......
Mar 3 09:26:47 node1 postfix/smtp[29350]: 00f0 01 02 00 0a 00 08 00
06|00 19 00 18 00 17 00 23 ........ .......#
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0100 00 00 00 0d 00 20 00
1e|06 01 06 02 06 03 05 01 ..... .. ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0110 05 02 05 03 04 01 04
02|04 03 03 01 03 02 03 03 ........ ........
Mar 3 09:26:47 node1 postfix/smtp[29350]: 0120 02 01 02 02 02 03 00
0f|00 01 01 ........ ...
Mar 3 09:26:47 node1 postfix/smtp[29350]: SSL_connect:SSLv2/v3 write
client hello A
Mar 3 09:26:47 node1 postfix/smtp[29350]: read from 7FAD076983A0
[7FAD0769F0D0] (7 bytes => -1 (0xFFFFFFFFFFFFFFFF))
Am 02.03.2016 um 22:10 schrieb Viktor Dukhovni:
Yes, the message is deferred when the TLS handshake fails. Later
it is retried and either TLS succeeds, or fallback to cleartext
happens. THere are probably more messages in the log about the
TLS failures. Perhaps your firewall is blocking TLS, but there no
information to work with in what you've posted so far.
Try ("collate" script attached):
# logfile=/var/log/mail.log # or whatever
# perl collate "${logfile}" |
perl -ne 'BEGIN {$/="\n\n"} print if m{5B0A235E18A}'
