I run
dovecot --version
2.3.10.1 (a3d0e1171)
postconf mail_version
mail_version = 3.5.7
with three valid accounts on the server,
[email protected]
[email protected]
[email protected]
I can send/receive from each -- both to/from external addresses, as well as
between one another.
E.g., on mail sent to
[email protected] -> [email protected]
logs of the successful delivery are
==> /var/log/dovecot/dovecot-info.log <==
2020-09-26 16:00:33 submission-login: Info: Login:
user=<[email protected]>, method=PLAIN, rip=10.0.1.9, lip=10.0.1.17,
mpid=7178, TLS
2020-09-26 16:00:33
submission([email protected])<gQePZj+wUuesHgsH>: Info: Successfully relayed
message: from=<[email protected]>, size=449, id=WjpMLRHIb18KHAAA+IOfAw,
nrcpt=1, reply=`250 2.0.0 Ok: queued as 4BzPQ95QwwzWf9g'
2020-09-26 16:00:33
submission([email protected])<gQePZj+wUuesHgsH>: Info: Disconnect from
10.0.1.9: Client has quit the connection in=566 out=114 (state=READY)
2020-09-26 16:00:33 imap([email protected])<YzPbWj+wzNCsHgsH>: Info:
save: box=Sent, uid=42,
msgid=<[email protected]>, size=434
2020-09-26 16:00:33 lmtp(7183): Info: Connect from local
2020-09-26 16:00:33 lmtp([email protected])<2HI4MBHIb18PHAAA+IOfAw>:
Info: msgid=<[email protected]>: saved mail to
INBOX
2020-09-26 16:00:33 lmtp(7183): Info: Disconnect from local: Client has
quit the connection (state=READY)
==> /var/log/postfix/postfix.log <==
Sep 26 16:00:33 mx postfix/submit-from-dovecot-proxy/smtpd[7179]:
connect from internal.mx.example.com[10.0.1.17]
Sep 26 16:00:33 mx postfix/submit-from-dovecot-proxy/smtpd[7179]:
Trusted TLS connection established from internal.mx.example.com[10.0.1.17]:
TLSv1.3 with cipher TLS_CHACHA20_POLY1305_SHA256 (256/256 bits) key-exchange
X25519 server-signature ECDSA (P-384) server-digest SHA384 client-signature
ECDSA (P-384) client-digest SHA384
Sep 26 16:00:33 mx postfix/submit-from-dovecot-proxy/smtpd[7179]:
4BzPQ95QwwzWf9g: client=internal.mx.example.com[10.0.1.17]
Sep 26 16:00:33 mx postfix/qmgr[6928]: 4BzPQ95QwwzWf9g:
from=<[email protected]>, size=824, nrcpt=1 (queue active)
Sep 26 16:00:33 mx postfix/submit-from-dovecot-proxy/smtpd[7179]:
disconnect from internal.mx.example.com[10.0.1.17] ehlo=1 mail=1 rcpt=1 data=1
quit=1 commands=5
Sep 26 16:00:33 mx postfix/lmtp[7182]: 4BzPQ95QwwzWf9g:
to=<[email protected]>, relay=mx.example.com[private/dovecot-lmtp],
delay=0.06, delays=0.03/0.01/0.01/0.02, dsn=2.0.0, status=sent (250 2.0.0
<[email protected]> 2HI4MBHIb18PHAAA+IOfAw Saved)
Sep 26 16:00:33 mx postfix/qmgr[6928]: 4BzPQ95QwwzWf9g: removed
==> /var/log/dovecot/dovecot-info.log <==
2020-09-26 16:00:33 imap([email protected])<YzPbWj+wzNCsHgsH>: Info:
Connection closed (IDLE running for 0.001 + waiting input for 0.009 secs, 2 B
in + 10 B out, state=wait-input) in=1199 out=3082 deleted=0 expunged=0
trashed=0 hdr_count=1 hdr_bytes=271 body_count=0 body_bytes=0
2020-09-26 16:00:33 imap-login: Info: Login: user=<[email protected]>,
method=PLAIN, rip=10.0.1.9, lip=10.0.1.17, mpid=7185, TLS
I've added a user sieve script for user == [email protected]
cat /srv/mail/sieve-scripts/[email protected]
# rule:[SIEVETEST]
if header :contains "subject" "SIEVETEST"
{
redirect "[email protected]";
}
where the redirect is to the valid address tested/demonstrated above,
[email protected]
in dovecot config,
submission_host = internal.mx.example.com:60465
currently,
host mx.example.com
mx.example.com has address 10.0.1.17
mx.example.com has IPv6 address fd70:10:0:1::17
host internal.mx.example.com
internal.mx.example.com has address 10.0.1.17
internal.mx.example.com has IPv6 address fd70:10:0:1::17
on test send from [email protected] to [email protected], with Subject ==
SIEVETEST
the user sieve _is_ triggered/executed
cat 20200926-160636.7461.1.trace
Sieve trace log for message delivery:
Username: [email protected]
Session ID: E851MXzJb18lHQAA+IOfAw
Sender: <[email protected]>
Final recipient: <[email protected]>
Default mailbox: INBOX
## Started executing script 'managesieve'
2: not jumping
4: redirect action
4: forward message to address <[email protected]>
## Finished executing script 'managesieve'
but the mail redirect delivery fails
2020-09-26 16:06:36 submission-login: Info: Login:
user=<[email protected]>, method=PLAIN, rip=10.0.1.9, lip=10.0.1.17,
mpid=7455, TLS
2020-09-26 16:06:36
submission([email protected])<VbsxfD+wXOesHgsH>: Info: Successfully relayed
message: from=<[email protected]>, size=466, id=lvK6LnzJb18fHQAA+IOfAw,
nrcpt=1, reply=`250 2.0.0 Ok: queued as 4BzPY85g9czWf8L'
2020-09-26 16:06:36
submission([email protected])<VbsxfD+wXOesHgsH>: Info: Disconnect from
10.0.1.9: Client has quit the connection in=567 out=114 (state=READY)
2020-09-26 16:06:36 lmtp(7461): Info: Connect from local
2020-09-26 16:06:36 imap([email protected])<0ZZlej+w2NCsHgsH>: Info:
save: box=Sent, uid=13177,
msgid=<[email protected]>, size=450
==> /var/log/postfix/postfix.log <==
Sep 26 16:06:36 mx postfix/submit-from-dovecot-proxy/smtpd[7456]:
connect from internal.mx.example.com[10.0.1.17]
Sep 26 16:06:36 mx postfix/submit-from-dovecot-proxy/smtpd[7456]:
Trusted TLS connection established from internal.mx.example.com[10.0.1.17]:
TLSv1.3 with cipher TLS_CHACHA20_POLY1305_SHA256 (256/256 bits) key-exchange
X25519 server-signature ECDSA (P-384) server-digest SHA384 client-signature
ECDSA (P-384) client-digest SHA384
Sep 26 16:06:36 mx postfix/submit-from-dovecot-proxy/smtpd[7456]:
4BzPY85g9czWf8L: client=internal.mx.example.com[10.0.1.17]
Sep 26 16:06:36 mx postfix/qmgr[7362]: 4BzPY85g9czWf8L:
from=<[email protected]>, size=812, nrcpt=1 (queue active)
Sep 26 16:06:36 mx postfix/submit-from-dovecot-proxy/smtpd[7456]:
disconnect from internal.mx.example.com[10.0.1.17] ehlo=1 mail=1 rcpt=1 data=1
quit=1 commands=5
==> /var/log/dovecot/dovecot.log <==
2020-09-26 16:07:06 lmtp([email protected])<E851MXzJb18lHQAA+IOfAw>:
Error: smtp-client: conn internal.mx.example.com:60465 (10.0.1.17:60465) [1]:
connect(internal.mx.example.com:60465) failed: Connection timed out after 30
seconds
2020-09-26 16:07:06 lmtp([email protected])<E851MXzJb18lHQAA+IOfAw>:
Error: sieve: msgid=<[email protected]>:
redirect action: failed to redirect message to <[email protected]>:
smtp(internal.mx.example.com:60465): RCPT TO failed: Connect timed out
(temporary failure)
2020-09-26 16:07:06 lmtp([email protected])<E851MXzJb18lHQAA+IOfAw>:
Error: sieve: Execution of script
/srv/mail/sieve-scripts/[email protected] was aborted due to temporary
failure (user logfile /srv/mail/sieve-scripts/[email protected] may
reveal additional details)
2020-09-26 16:07:06 submission-login: Error: smtp-server: conn
10.0.1.17:50578 [1]: Connection lost: read((conn:10.0.1.17:50578,id=1)) failed:
SSL_accept() failed: error:1408F10B:SSL routines:ssl3_get_record:wrong version
number
2020-09-26 16:07:06 submission-login: Info: Read failure (client didn't
send a cert): user=<>, rip=10.0.1.17, lip=10.0.1.17, TLS handshaking:
SSL_accept() syscall failed: Invalid argument
2020-09-26 16:07:06 lmtp(7461): Info: Disconnect from local: Client has
quit the connection (state=READY)
==> /var/log/postfix/postfix.log <==
Sep 26 16:07:06 mx postfix/lmtp[7460]: 4BzPY85g9czWf8L:
to=<[email protected]>, relay=mx.example.com[private/dovecot-lmtp], delay=30,
delays=0.04/0/0/30, dsn=4.2.0, status=deferred (host
mx.example.com[private/dovecot-lmtp] said: 451 4.2.0 <[email protected]>
Execution of Sieve filters was aborted due to temporary failure (in reply to
end of DATA command))
&
cat /srv/mail/sieve-scripts/[email protected]
sieve: info: started log at Sep 26 16:07:06.
error:
msgid=<[email protected]>: redirect action:
failed to redirect message to <[email protected]>:
smtp(internal.mx.example.com:60465): RCPT TO failed: Connect timed out
(temporary failure).
and remains stuck in postfix queue
postqueue -p
----Queue ID----- --Size-- ---Arrival Time----
--Sender/Recipient------
4BzPY85g9czWf8L 812 Sat Sep 26 16:06:36
[email protected]
(host mx.example.com[private/dovecot-lmtp] said: 451 4.2.0
<[email protected]> Execution of Sieve filters was aborted due to temporary
failure (in reply to end of DATA command))
[email protected]
-- 0 Kbytes in 1 Request.
it appears there's an SSL/cert problem -- but only in the case of the redirect.
i.e.., this direct send,
[email protected] --SEND--> [email protected]
works, but the redirect
[email protected] (subjet == "SIEVETEST") --SEND--> [email protected]
--REDIRECT--> [email protected]
does not, failing as above.
i suspect i'm missing config, but what/where in the dovecot submission/sieve
configs addresses this^ point in the SSL transaction?
