- dovecot - dovecot.org

Dsync issues since 2.3.11.3.
by Reio Remma 02 Oct '20

02 Oct '20

Hello! I've started seeing intermittent dsync failures since upgrading Dovecot to 2.3.11.3-3 (CentOS 8 using the official Dovecot repo). Sep 27 17:49:04 host dovecot[130]: dsync-local(user@host)<5GWFD2CmcF+TJwAAsNnMGQ>: Warning: Failed to do incremental sync for mailbox INBOX, retry with a full sync (Modseq 66543 no longer in transaction log (highest=66547, last_common_uid=46346, nextuid=46347)) Sep 27 17:49:04 host dovecot[130]: dsync-local(user@host)<5GWFD2CmcF+TJwAAsNnMGQ>: Error: Remote command returned error 75: ssh <options> doveadm dsync-server -u user@host It seems to happen at random times to random users. My setup has 2 servers - users are connecting to the main server and the secondary server is just for backup - noone is actually connecting to it. Any suggestions? Thanks! Reio

1 2

Re: BUG: _presence_ of valid openssl.cnf Option = 'ServerPreference' causes Dovecot submission relay FAIL: "failed: Failed to initialize SSL: ..."
by PGNet Dev 01 Oct '20

01 Oct '20

hi, On 10/1/20 12:21 AM, JEAN-PAUL CHAPALAIN wrote: > I had the same problem when migrating from Dovecot V2.2.36 on, Centos-7 to Dovecot v2.3.8 on Centos-8 My report is specifically/solely about the addition/use of the Options = ServerPreference parameter. I don't see that in your configuration. Are you using it? In a config using Dovecot's submission proxy?

2 3

dovecot lda deliver_log_format question
by rudolf＠padaru.de 01 Oct '20

01 Oct '20

Hey, i have an question about the deliver_log_format. My log looks sometimes like: Oct 1 09:38:01 dd44414 dovecot: lda(user)<20009><9MYzGVmHdV8pTgAA+v7NQw>: msgid=<20201001073801.628713AC05DC(a)myserver.com>: saved mail to INBOX The deliver_log_format settings are still on default. Are somebody able to explain me this part of the log message? <20009><9MYzGVmHdV8pTgAA+v7NQw>: What want dovecot to say with this? Mit freundlichen Grüßen Yours sincerely Pascal Rudolf

2 1

debugging TLS with wireshark and a custom application ?
by Kurt Jaeger 01 Oct '20

01 Oct '20

Hi! My question is: can dovecot be used to debug/decrypt TLS sessions ? The reason I'm asking: A custom application wants to speak IMAP with TLS with a dovecot instance. It fails, and the error message is, unfortunatly, not very helpful. tcpdump shows that the session is established, but fails. The custom application says error 60000, not much more. There is a way to decode TLS sessions in some cases: https://wiki.wireshark.org/TLS using firefox and the enviroment variable SSLKEYLOGFILE. Basically, the TLS client (firefox), while negotiating keys with the other side, writes those logfiles to a logfile specified by SSLKEYLOGFILE and at the same time, wireshark is used to capture / write the pcap of the session. Then wireshark can be used to decode the contents of the TLS-encrypted session. Is something similiar possible with dovecot as the server and from the server side ? Is, by chance, the session=<...> value already such a key so that a tcpdump pcap file would be able to descrypt that session ? Sep 29 08:51:30 imap-login: Info: Login: user=<someuser>, method=PLAIN, rip=<someip>, lip=<someotherip>, mpid=63667, TLS, session=<GGF0Nm6wxy0qAQHoAAMAAwAAAAAAAAAB> -- pi(a)opsec.eu +49 171 3101372 Now what ?

3 2

auth_username_format effective only within passdb/userdb
by Bob 30 Sep '20

30 Sep '20

Hello dovecot list. I have multiple passdb/userdb, some use %Ln some use %Lu. How to make auth_username_format effective only within passdb/userdb?

2 2

Leaked files in maildir "tmp" after vsz_limit crashes
by Peter Mogensen 30 Sep '20

30 Sep '20

Hi, Lately I've seen a few examples of users hitting the vsz_limit (usually trying to "delete" mails i Spam/Junk by moving them to Trash with a large dovecot.index.cache - which resulted in mails left/leaked in the tmp directory of Trash. Sometimes it seems the client gets into a state were it repeatedly tried to sync the client and server state so it does it again and again, building up the number of files/links in tmp. It seems the default 1 week interval to "unlink_old_files()" is not enough to prevent this from blowing up inode wise. However, ... lowering it, - or increasing vsz_limit feels a bit like kicking the can down the road. PS: This on dovecot 2.2.36 /Peter

2 1

Re: Dovecot permission denied errors on NFS after upgrade to 2.2.17
by Claudio Corvino 29 Sep '20

29 Sep '20

Thanks Jochen, no mixups present at all, file assigned to UID 501. Since this problem started few hours after the Debian upgrade, I think it is related to it. I don't know if something has changed on the NFS client side on Debian, but I don't think so as aptlistchanges didn't notify me about it, nor if Dovecot 2.2.17 treat NFS in other way. I'm stuck. On 13/07/20 16:07, Jochen Bern wrote: > On 07/13/2020 03:45 PM, Claudio Corvino wrote: >> in addition the "permission denied" error is >> random, most of the time Dovecot works well. > In *that* case, I'd say that UID/GID mapping problems can be ruled out. > >> How can I check the mappings NFS uses? > You don't have any relevant options in the client's fstab entry, and > I'll assume that there are none in the server's /etc/exports, either. > That leaves only potential default mappings, which should be documented > in the corresponding manpages. > > Also, since there's only *one* user/group involved, you can always > "chown" a test file on one side and check with "ls -n" on the other to > verify whether there are mixups. > > *Intermittent* failures of an NFS mount over a well-functioning LAN ... > I'm thinking "file locking" now, but that's a *complicated* topic, to > say the least ... > > https://en.wikipedia.org/wiki/File_locking#Problems > https://unix.stackexchange.com/questions/553645/how-to-install-nfslock-daem… > > Regards,

4 8

Re-sieve emails
by ＠lbutlr 29 Sep '20

29 Sep '20

Is it possible to take the contents of a mailbox and feed them to the account's .active_sieve file for reprocessing? (For example, when editing the sieve file for my list account I introduced a typo, so a hundred or some list messages ended up in the inbox instead of filed properly into the maildir hierarchy. Not a huge deal, as it was simple enough to move them manually, but it got me wondering. This would also be useful for testing. -- Clarke's Law: Sufficiently advanced technology is indistinguishable from magic Clark's Law: Sufficiently advanced cluelessness is indistinguishable from malice Clark Slaw: Anything that has been severely damaged or destroyed by application of Clark's Law

2 4

dovecot warns (non-fatal) "invalid EHLO response line: Unexpected character in EHLO keyword" connecting to submission relay ?
by PGNet Dev 29 Sep '20

29 Sep '20

I'm setting up an alternative submission relay host for dovecot. Atm, it's pointing @ fastmail.com. with dovecot config, submission_relay_host = smtp.fastmail.com submission_relay_port = 465 submission_relay_ssl = smtps submission_relay_ssl_verify = no submission_relay_trusted = yes submission_relay_user = 'acctID(a)mydomain.com' submission_relay_password = 'acctPWD' submission relay via dovecot proxy works as expected -- mail's delivered/received by intended recipient. in local dovecot logs I notice ==> /var/log/dovecot/dovecot.log <== 2020-09-24 16:22:19 submission(recipient(a)example.com)<xxxxxxxxxxxxxxxx>: Warning: smtp-client: conn smtp.fastmail.com:465 (66.111.4.140:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword at debug level ==> /var/log/dovecot/dovecot-debug.log <== 2020-09-24 16:22:19 submission(recipient(a)example.com)<xxxxxxxxxxxxxxxx>: Debug: smtp-client: conn smtp.fastmail.com:465 (66.111.4.140:465) [1]: command EHLO: Got reply (1/1): 250 mail.messagingengine.com PIPELINING SIZE 73000000 AUTH DIGEST-MD5 CRAM-MD5 NTLM LOGIN PLAIN AUTH=DIGEST-MD5 CRAM-MD5 NTLM LOGIN PLAIN ENHANCEDSTATUSCODES 8BITMIME (1 commands pending, 0 commands queued) it's clearly non-fatal, simply a warning. i certainly do _not_ see this with every relay host, so suspect it's unique to fastmail's EHLO response. at least within the set of hosts I've tested. i'd like to find/fix it ... either at my dovecot instance, or @ fastmail. what's specifically invalid about 250 mail.messagingengine.com PIPELINING SIZE 73000000 AUTH DIGEST-MD5 CRAM-MD5 NTLM LOGIN PLAIN AUTH=DIGEST-MD5 CRAM-MD5 NTLM LOGIN PLAIN ENHANCEDSTATUSCODES 8BITMIME by dovecot's 'measure'?

3 3

managesieve script 'redirect' fails @ "Error: sieve: ... aborted due to temporary failure; Error: smtp-server: ... failed: SSL_accept() failed: error:1408F10B:SSL routines:ssl3_get_record:wrong version number"; direct send OK ?
by PGNet Dev 29 Sep '20

29 Sep '20

I run dovecot --version 2.3.10.1 (a3d0e1171) postconf mail_version mail_version = 3.5.7 with three valid accounts on the server, user1(a)example1.net user2(a)example2.net admin(a)mx.example.com I can send/receive from each -- both to/from external addresses, as well as between one another. E.g., on mail sent to user2(a)example2.net -> admin(a)mx.example.com logs of the successful delivery are ==> /var/log/dovecot/dovecot-info.log <== 2020-09-26 16:00:33 submission-login: Info: Login: user=<sender(a)mx.example.com>, method=PLAIN, rip=10.0.1.9, lip=10.0.1.17, mpid=7178, TLS 2020-09-26 16:00:33 submission(sender(a)mx.example.com)<gQePZj+wUuesHgsH>: Info: Successfully relayed message: from=<user2(a)example2.net>, size=449, id=WjpMLRHIb18KHAAA+IOfAw, nrcpt=1, reply=`250 2.0.0 Ok: queued as 4BzPQ95QwwzWf9g' 2020-09-26 16:00:33 submission(sender(a)mx.example.com)<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(user2(a)example2.net)<YzPbWj+wzNCsHgsH>: Info: save: box=Sent, uid=42, msgid=<9ca622bd-cdc3-ca26-8650-556d4132fe6c(a)example2.net>, size=434 2020-09-26 16:00:33 lmtp(7183): Info: Connect from local 2020-09-26 16:00:33 lmtp(admin(a)mx.example.com)<2HI4MBHIb18PHAAA+IOfAw>: Info: msgid=<9ca622bd-cdc3-ca26-8650-556d4132fe6c(a)example2.net>: 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=<user2(a)example2.net>, 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=<admin(a)mx.example.com>, 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 <admin(a)mx.example.com> 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(user2(a)example2.net)<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=<user2(a)example2.net>, method=PLAIN, rip=10.0.1.9, lip=10.0.1.17, mpid=7185, TLS I've added a user sieve script for user == user2(a)example2.net cat /srv/mail/sieve-scripts/user2(a)example2.net.sieve # rule:[SIEVETEST] if header :contains "subject" "SIEVETEST" { redirect "admin(a)mx.example.com"; } where the redirect is to the valid address tested/demonstrated above, admin(a)mx.example.com 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 user1(a)example1.net to user2(a)example2.net, with Subject == SIEVETEST the user sieve _is_ triggered/executed cat 20200926-160636.7461.1.trace Sieve trace log for message delivery: Username: user2(a)example2.net Session ID: E851MXzJb18lHQAA+IOfAw Sender: <user1(a)example1.net> Final recipient: <user2(a)example2.net> Default mailbox: INBOX ## Started executing script 'managesieve' 2: not jumping 4: redirect action 4: forward message to address <admin(a)mx.example.com> ## Finished executing script 'managesieve' but the mail redirect delivery fails 2020-09-26 16:06:36 submission-login: Info: Login: user=<sender(a)mx.example.com>, method=PLAIN, rip=10.0.1.9, lip=10.0.1.17, mpid=7455, TLS 2020-09-26 16:06:36 submission(sender(a)mx.example.com)<VbsxfD+wXOesHgsH>: Info: Successfully relayed message: from=<user1(a)example1.net>, size=466, id=lvK6LnzJb18fHQAA+IOfAw, nrcpt=1, reply=`250 2.0.0 Ok: queued as 4BzPY85g9czWf8L' 2020-09-26 16:06:36 submission(sender(a)mx.example.com)<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(user1(a)example1.net)<0ZZlej+w2NCsHgsH>: Info: save: box=Sent, uid=13177, msgid=<28930f55-5a39-c8bd-67c2-39e581aa7551(a)example1.net>, 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=<user1(a)example1.net>, 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(user2(a)example2.net)<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(user2(a)example2.net)<E851MXzJb18lHQAA+IOfAw>: Error: sieve: msgid=<28930f55-5a39-c8bd-67c2-39e581aa7551(a)example1.net>: redirect action: failed to redirect message to <admin(a)mx.example.com>: smtp(internal.mx.example.com:60465): RCPT TO failed: Connect timed out (temporary failure) 2020-09-26 16:07:06 lmtp(user2(a)example2.net)<E851MXzJb18lHQAA+IOfAw>: Error: sieve: Execution of script /srv/mail/sieve-scripts/user2(a)example2.net.sieve was aborted due to temporary failure (user logfile /srv/mail/sieve-scripts/user2(a)example2.net.sieve.log 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=<user2(a)example2.net>, 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 <user2(a)example2.net> Execution of Sieve filters was aborted due to temporary failure (in reply to end of DATA command)) & cat /srv/mail/sieve-scripts/user2(a)example2.net.sieve.log sieve: info: started log at Sep 26 16:07:06. error: msgid=<28930f55-5a39-c8bd-67c2-39e581aa7551(a)example1.net>: redirect action: failed to redirect message to <admin(a)mx.example.com>: 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 user1(a)example1.net (host mx.example.com[private/dovecot-lmtp] said: 451 4.2.0 <user2(a)example2.net> Execution of Sieve filters was aborted due to temporary failure (in reply to end of DATA command)) user2(a)example2.net -- 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, user2(a)example2.net --SEND--> admin(a)mx.example.com works, but the redirect user1(a)example1.net (subjet == "SIEVETEST") --SEND--> user2(a)example2.net --REDIRECT--> admin(a)mx.example.com 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?

1 3