March 2019 - dovecot - dovecot.org

v2.2.27 Panic: file rfc822-parser.h: line 23 (rfc822_parser_deinit): assertion failed: (ctx->data <= ctx->end)
by Jason Lewis 29 Mar '19

29 Mar '19

Hi, I've been having an issue with the indexer giving me errors on mailbox in dovecot. I managed to narrow it down to a specific email in that mailbox. Various dovecot functions have issues with this email. The email itself is just spam. I can email it to you if you want to analyse it. I did run it through mbox-anonymize but its not clear to me that that would be of any use. Happy to email the suspect email privately to anyone who wants it. /home is mounted nfs4 and is zfs on the nfs server. Dovecot is installed from Debian Jessie. $ /usr/sbin/dovecot --version 2.2.27 (c0f36b0) dovecot-core: Installed: 1:2.2.27-3+deb9u2~bpo8+1 Candidate: 1:2.2.27-3+deb9u2~bpo8+1 Version table: *** 1:2.2.27-3+deb9u2~bpo8+1 0 100 /var/lib/dpkg/status 1:2.2.13-12~deb8u5 0 400 http://security.debian.org/ jessie/updates/main amd64 Packages 1:2.2.13-12~deb8u4 0 400 http://deb.debian.org/debian/ jessie/main amd64 Packages ~# dovecot -n # 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf # Pigeonhole version 0.4.16 (fed8554) # OS: Linux 4.9.0-0.bpo.6-amd64 x86_64 Debian 8.10 imap_hibernate_timeout = 5 secs mail_location = maildir:~/Maildir mail_plugins = fts fts_solr mailbox_list_index = yes namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { driver = pam } plugin { fts = solr fts_autoindex = yes fts_enforced = yes fts_solr = url=http://10.0.2.19:8080/solr/ imapsieve_mailbox1_before = file:/etc/dovecot/train-as-spam.sieve imapsieve_mailbox1_causes = COPY imapsieve_mailbox1_name = Junk imapsieve_mailbox2_before = file:/etc/dovecot/train-as-ham.sieve imapsieve_mailbox2_causes = COPY imapsieve_mailbox2_from = Junk imapsieve_mailbox2_name = * sieve = file:~/sieve;active=~/.dovecot.sieve sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment sieve_pipe_bin_dir = /usr/bin sieve_plugins = sieve_imapsieve sieve_extprograms } protocols = " imap" service anvil { client_limit = 1127 } service auth { client_limit = 2200 unix_listener /var/spool/postfix/private/auth { mode = 0666 } } service imap-hibernate { unix_listener imap-hibernate { group = dovecot mode = 0660 } } service imap-login { process_limit = 1024 process_min_avail = 12 service_count = 0 vsz_limit = 1 G } service imap { extra_groups = dovecot unix_listener imap-master { user = dovecot } } ssl_cert = </etc/letsencrypt/live/imap.organictrader.com.au/fullchain.pem ssl_key = # hidden, use -P to show it userdb { driver = passwd } protocol imap { mail_max_userip_connections = 20 mail_plugins = fts fts_solr imap_sieve } jason@debian:~$ doveadm -D -f flow fetch imap.envelope mailbox crm-spam.2008.g Debug: Loading modules from directory: /usr/lib/dovecot/modules Debug: Module loaded: /usr/lib/dovecot/modules/lib20_fts_plugin.so Debug: Module loaded: /usr/lib/dovecot/modules/lib21_fts_solr_plugin.so Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm Debug: Skipping module doveadm_acl_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so: undefined symbol: acl_user_module (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_expire_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so: undefined symbol: expire_set_deinit (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_quota_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so: undefined symbol: quota_user_module (this is usually intentional, so just ignore this message) Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_sieve_plugin.so Debug: Skipping module doveadm_fts_lucene_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_lucene_plugin.so: undefined symbol: lucene_index_iter_deinit (this is usually intentional, so just ignore this message) Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_plugin.so Debug: Skipping module doveadm_mail_crypt_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/libdoveadm_mail_crypt_plugin.so: undefined symbol: mail_crypt_box_get_pvt_digests (this is usually intentional, so just ignore this message) doveadm(jason): Debug: Effective uid=1000, gid=1000, home=/home/jason doveadm(jason): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir doveadm(jason): Debug: maildir++: root=/home/jason/Maildir, index=, indexpvt=, control=, inbox=/home/jason/Maildir, alt= doveadm(jason): Debug: Namespace : Using permissions from /home/jason/Maildir: mode=0700 gid=default doveadm(jason): Debug: Mailbox crm-spam.2008.g: Opened mail UID=38 because: 1/10 headers not cached (first=Sender) (Mail has other cached fields, reset_id=1553472765) doveadm(jason): Panic: file rfc822-parser.h: line 23 (rfc822_parser_deinit): assertion failed: (ctx->data <= ctx->end) doveadm(jason): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x989ae) [0x7f170b1389ae] -> /usr/lib/dovecot/libdovecot.so.0(+0x98a28) [0x7f170b138a28] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f170b0ce67e] -> /usr/lib/dovecot/libdovecot.so.0(+0x7c97d) [0x7f170b11c97d] -> /usr/lib/dovecot/libdovecot.so.0(message_address_parse+0x55) [0x7f170b11c9e5] -> /usr/lib/dovecot/libdovecot.so.0(imap_envelope_parse_header+0x144) [0x7f170b110374] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mail_parse_header+0xfe) [0x7f170b47422e] -> /usr/lib/dovecot/libdovecot.so.0(+0x7979f) [0x7f170b11979f] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x53) [0x7f170b1437e3] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d) [0x7f170b14422d] -> /usr/lib/dovecot/libdovecot.so.0(message_parse_header_next+0x72) [0x7f170b11f3d2] -> /usr/lib/dovecot/libdovecot.so.0(message_parse_header+0x4f) [0x7f170b11fd7f] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mail_headers_get_envelope+0x138) [0x7f170b475448] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mail_get_special+0x1a1) [0x7f170b4796c1] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x69dd3) [0x7f170b42fdd3] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_get_special+0xd) [0x7f170b400a8d] -> /usr/bin/doveadm(+0x2dca8) [0x562378dd4ca8] -> /usr/bin/doveadm(+0x2ed7e) [0x562378dd5d7e] -> /usr/bin/doveadm(+0x2a57c) [0x562378dd157c] -> /usr/bin/doveadm(+0x2b0da) [0x562378dd20da] -> /usr/bin/doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x21f) [0x562378dd2f5f] -> /usr/bin/doveadm(doveadm_cmd_run_ver2+0x560) [0x562378de2390] -> /usr/bin/doveadm(doveadm_cmd_try_run_ver2+0x37) [0x562378de23e7] -> /usr/bin/doveadm(main+0x1e4) [0x562378dc1f44] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f170ad16b45] -> /usr/bin/doveadm(+0x1b32c) [0x562378dc232c] Aborted (core dumped) jason@debian:~$ gdb /usr/bin/doveadm /home/jason/core GNU gdb (Debian 7.7.1+dfsg-5) 7.7.1 Copyright (C) 2014 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/bin/doveadm...(no debugging symbols found)...done. [New LWP 22454] Core was generated by `/usr/bin/doveadm -D -f flow fetch imap.envelope mailbox crm-spam.2008.g'. Program terminated with signal SIGABRT, Aborted. #0 0x00007f170ad2a067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory. (gdb) bt full #0 0x00007f170ad2a067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 resultvar = 0 pid = 22454 selftid = 22454 #1 0x00007f170ad2b448 in __GI_abort () at abort.c:89 save_stage = 2 act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {1024, 94710351668199, 94710351535940, 139736942472005, 94710351536940, 0, 94710367714600, 513, 13251895700223756544, 94710367714600, 139736946974659, 94710367714600, 140734907147216, 4294967040, 139736946975017, 94710367714600}}, sa_flags = 185808618, sa_restorer = 0x7fff6625e401} sigs = {__val = {32, 0 <repeats 15 times>}} #2 0x00007f170b1389a6 in ?? () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #3 0x00007f170b138a28 in default_fatal_handler () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #4 0x00007f170b0ce67e in i_panic () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #5 0x00007f170b11c97d in ?? () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #6 0x00007f170b11c9e5 in message_address_parse () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #7 0x00007f170b110374 in imap_envelope_parse_header () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #8 0x00007f170b47422e in index_mail_parse_header () from /usr/lib/dovecot/libdovecot-storage.so.0 No symbol table info available. #9 0x00007f170b11979f in ?? () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #10 0x00007f170b1437e3 in i_stream_read () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #11 0x00007f170b14422d in i_stream_read_data () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #12 0x00007f170b11f3d2 in message_parse_header_next () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #13 0x00007f170b11fd7f in message_parse_header () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #14 0x00007f170b475448 in index_mail_headers_get_envelope () from /usr/lib/dovecot/libdovecot-storage.so.0 No symbol table info available. #15 0x00007f170b4796c1 in index_mail_get_special () from /usr/lib/dovecot/libdovecot-storage.so.0 No symbol table info available. #16 0x00007f170b42fdd3 in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 No symbol table info available. ---Type <return> to continue, or q <return> to quit--- #17 0x00007f170b400a8d in mail_get_special () from /usr/lib/dovecot/libdovecot-storage.so.0 No symbol table info available. #18 0x0000562378dd4ca8 in ?? () No symbol table info available. #19 0x0000562378dd5d7e in ?? () No symbol table info available. #20 0x0000562378dd157c in ?? () No symbol table info available. #21 0x0000562378dd20da in ?? () No symbol table info available. #22 0x0000562378dd2f5f in doveadm_cmd_ver2_to_mail_cmd_wrapper () No symbol table info available. #23 0x0000562378de2390 in doveadm_cmd_run_ver2 () No symbol table info available. #24 0x0000562378de23e7 in doveadm_cmd_try_run_ver2 () No symbol table info available. #25 0x0000562378dc1f44 in main () No symbol table info available. (gdb) -- Jason Lewis http://emacstragic.net

5 9

Apparmor problem
by Ervin Hegedüs 28 Mar '19

28 Mar '19

Hi there, I know this isn't a Dovecot issue, but hope that somebody can helps me. I've successfully installed and configured Dovecot to a Debian 9 server. Looks like everything works as well, I just see a line in the log when I send a mail: Mar 28 22:21:47 mailng kernel: [3150146.825007] audit: type=1400 audit(1553808107.757:286204): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/dovecot-lda" name="/usr/share/dovecot/protocols.d/" pid=26197 comm="doveconf" requested_mask="r" denied_mask="r" fsuid=5000 ouid=0 The /usr/share/dovecot/protocols.d/ directory and its content (.../protocols.d/**) set up in usr.lib.dovecot.dovecot-lda apparmor profile with mask "r", but this line every time comes, when I send a mail through webmail - think when the client copies the message to the Sent folder (anyway, the sent messages are in Sent folder after sending, so everything works). Do you have any idea? Thanks, a.

1 0

Hibernation and proxy
by azurit＠pobox.sk 28 Mar '19

28 Mar '19

Hi, does hibernation works well with proxy? Are proxy connections hibernated or not? azur

2 3

Regression ACL & namespace prefix
by Michal Hlavinka 28 Mar '19

28 Mar '19

Hi tl;dr: Seems that for Global ACL directory, namespace prefix is not part of the path, when looking for acl file. Long version: We're planning to update dovecot in next os update to 2.2.36 and while going through regression testing, we found a problem with ACL configuration combined with namespace. Test uses "Global ACL directory" configuration. Relevant configuration part: mail_location = maildir:~/Maildir namespace inbox { hidden = no inbox = yes list = yes location = prefix = separator = / } namespace { hidden = no list = yes location = maildir:/var/mail/pub prefix = pub/ separator = / type = public } mail_plugins = acl protocol imap { mail_plugins = $mail_plugins acl imap_acl } plugin { acl = vfile:/etc/dovecot/global-acls } ACL config file is stored at: /etc/dovecot/global-acls/pub/.DEFAULT when trying to examine "pub", it is denied: fetchmail: IMAP> A0005 EXAMINE "pub" fetchmail: IMAP< A0005 NO Mailbox doesn't exist: pub (0.001 + 0.000 secs). # doveadm acl debug -u d2 pub doveadm(d2): Info: Mailbox '' is in namespace 'pub/' doveadm(d2): Info: Mailbox path: /var/mail/pub doveadm(d2): Info: All message flags are shared across users in mailbox doveadm(d2): Info: User d2 has no rights for mailbox doveadm(d2): Error: User d2 is missing 'lookup' right doveadm(d2): Info: Mailbox pub is NOT visible in LIST because it did not find acl file: imap(d2): Debug: Namespace : type=public, prefix=pub/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes location=maildir:/var/mail/pub imap(d2): Debug: maildir++: root=/var/mail/pub, index=, indexpvt=, control=, inbox=, alt= imap(d2): Debug: acl: initializing backend with data: vfile:/etc/dovecot/global-acls imap(d2): Debug: acl: acl username = d2 imap(d2): Debug: acl: owner = 0 imap(d2): Debug: acl vfile: Global ACL legacy directory: /etc/dovecot/global-acls imap(d2): Debug: pub: Mailbox opened because: EXAMINE imap(d2): Debug: acl vfile: file /etc/dovecot/global-acls//.DEFAULT not found imap(d2): Debug: acl vfile: file /var/mail/pub/dovecot-acl not found see it's looking for: /etc/dovecot/global-acls//.DEFAULT instead of /etc/dovecot/global-acls/pub/.DEFAULT Checking with documentation https://wiki.dovecot.org/ACL it seems that prefix should still be part of the path, as it was before: """The filenames must start with namespace prefix (if it has one). For example with namespace prefix=INBOX/ containing mailbox "foo" use /etc/dovecot/acls/INBOX/foo.""" Just for comparison, previous version (2.2.10) would work fine: imap(d2): Debug: Namespace : type=public, prefix=pub/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes location=maildir:/var/mail/pub imap(d2): Debug: maildir++: root=/var/mail/pub, index=, indexpvt=, control=, inbox=, alt= imap(d2): Debug: acl: initializing backend with data: vfile:/etc/dovecot/global-acls imap(d2): Debug: acl: acl username = d2 imap(d2): Debug: acl: owner = 0 imap(d2): Debug: acl vfile: Global ACL directory: /etc/dovecot/global-acls imap(d2): Debug: acl vfile: reading file /etc/dovecot/global-acls/pub/.DEFAULT imap(d2): Debug: acl vfile: file /var/mail/pub/dovecot-acl not found I've localized problem to: src/plugins/acl/acl-backend-vfile.c: acl_backend_vfile_object_init(...) and change from: vname = mailbox_list_get_vname(_backend->list, name); to: vname = *name == '\0' ? "" : mailbox_list_get_vname(_backend->list, name); that happened quite time ago during bigger acl changes and I don't know why exactly this line was changed previously. Anyway, reverting this line alone fixes the problem and while testing both per-mailbox ACL vfile and Global ACL file, reverting this did not affect them.

3 7

CVE-2019-7524 backport patch for 2.2.33.2
by Gerald Galster 28 Mar '19

28 Mar '19

Hello Aki, I'm currently stuck with 2.2.33.2 as 2.2.36 still duplicates mails after pop3 deletion on a two node dsync cluster. Therefore I've created a small patch and it seems only these two files are affected: dovecot-2.2.36.3/src/lib-storage/index/index-pop3-uidl.c dovecot-2.2.36.3/src/plugins/fts/fts-api.c Please correct me if I have missed something. Best regards Gerald

2 1

CVE-2019-7524: Buffer overflow when reading extension header from dovecot index files
by Aki Tuomi 28 Mar '19

28 Mar '19

Product: Dovecot Vendor: OX Software GmbH Internal reference: DOV-2964 (Bug ID) Vulnerability type: CWE-120 Vulnerable version: 2.0.14 - 2.3.5 Vulnerable component: fts, pop3-uidl-plugin Report confidence: Confirmed Researcher credits: Found in internal testing Solution status: Fixed by Vendor Fixed version: 2.3.5.1, 2.2.36.3 Vendor notification: 2019-02-05 Solution date: 2019-03-21 Public disclosure: 2019-03-28 CVE reference: CVE-2019-7524 CVSS: 3.0/AV:L/AC:L/PR:L/UI:N/S:C/C:H/I:H/A:H/E:P/RL:O/RC:C (8.8) Vulnerability Details: When reading FTS or POP3-UIDL header from dovecot index, the input buffer size is not bound, and data is copied to target structure causing stack overflow. Risk: This can be used for local root privilege escalation or executing arbitrary code in dovecot process context. This requires ability to directly modify dovecot indexes. Steps to reproduce: Produce dovecot.index.log entry that creates an FTS header which has more than 12 bytes of data. Trigger dovecot indexer-worker or run doveadm index. Dovecot will crash. Mitigations: Since 2.3.0 dovecot has been compiled with stack smash protection, ASLR, read-only GOT tables and other techniques that make exploiting this bug much harder. Solution: Operators should update to the latest Patch Release. The only workaround is to disable FTS and pop3-uidl plugin. -- Aki Tuomi Open-Xchange Oy

2 4

v2.2.36.3 released
by Aki Tuomi 28 Mar '19

28 Mar '19

https://dovecot.org/releases/2.3/dovecot-2.2.36.3.tar.gz https://dovecot.org/releases/2.3/dovecot-2.2.36.3.tar.gz.sig * CVE-2019-7524: Missing input buffer size validation leads into arbitrary buffer overflow when reading fts or pop3 uidl header from Dovecot index. Exploiting this requires direct write access to the index files. --- Aki Tuomi Open-Xchange oy

1 1

dovecot mailing list stopped delivering mail
by Christian Anthon 28 Mar '19

28 Mar '19

Strangest thing. Since some time Marts 25. I'm no longer receiving mails from the dovecot mailing list server. Mails from other sources are behaving fine. Instead I'm just seing Mar 26 08:27:54 dna01 postfix/smtpd[107746]: Anonymous TLS connection established from talvi.dovecot.org[94.237.25.159]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) Mar 26 08:27:54 dna01 postfix/smtpd[107746]: disconnect from talvi.dovecot.org[94.237.25.159] ehlo=1 starttls=1 quit=1 commands=3 And then no more. I tried turning up the postfix verbosity, but I'm none the wiser. I realize that this is probably not a dovecot issue, but anybody with any ideas? Cheers, Christian (and please send an off-list reply also) Verbose log: Mar 28 10:57:42 dna01 postfix/smtpd[66648]: connection established Mar 28 10:57:42 dna01 postfix/smtpd[66648]: master_notify: status 0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: name_mask: resource Mar 28 10:57:42 dna01 postfix/smtpd[66648]: name_mask: software Mar 28 10:57:42 dna01 postfix/smtpd[66648]: connect from talvi.dovecot.org[94.237.25.159] Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: smtp_stream_setup: maxtime=300 enable_deadline=0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 192.168.3.0/24 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 192.168.3.0/24 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 127.0.0.0/8 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 127.0.0.0/8 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr request = connect Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr ident = smtp:94.237.25.159 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: count Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: count Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 1 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: rate Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: rate Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 1 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: (list terminator) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: report connect to all milters Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "j" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "genome.ku.dk" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{daemon_name}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "genome.ku.dk" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{daemon_addr}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "192.168.3.112" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "v" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "Postfix 3.3.3" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: non-protocol events for protocol version 6: Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: transport=inet endpoint=localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: trying... [127.0.0.1] Mar 28 10:57:42 dna01 postfix/smtpd[66648]: vstream_tweak_tcp: TCP_MAXSEG 32741 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: fd=11: stream buffer size old=0 new=65482 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: my_version=0x6 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: milter inet:localhost:11332 version 6 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: events SMFIP_NR_HDR SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_conn_event: milter inet:localhost:11332: connect talvi.dovecot.org/94.237.25.159 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: event: SMFIC_CONNECT; macros: j=genome.ku.dk {daemon_name}=genome.ku.dk {daemon_addr}=192.168.3.112 v=Postfix 3.3.3 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: skipping reply for event SMFIC_CONNECT from milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 220 genome.ku.dk ESMTP Postfix Mar 28 10:57:42 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: EHLO talvi.dovecot.org Mar 28 10:57:42 dna01 postfix/smtpd[66648]: report helo to all milters Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{tls_version}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cipher}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cipher_bits}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cert_subject}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cert_issuer}" Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_helo_event: milter inet:localhost:11332: helo talvi.dovecot.org Mar 28 10:57:42 dna01 postfix/smtpd[66648]: event: SMFIC_HELO; macros: (none) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: skipping reply for event SMFIC_HELO from milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-genome.ku.dk Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-PIPELINING Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-SIZE 150000000 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-VRFY Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-ETRN Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-STARTTLS Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-ENHANCEDSTATUSCODES Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-8BITMIME Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250 DSN Mar 28 10:57:42 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: STARTTLS Mar 28 10:57:42 dna01 postfix/smtpd[66648]: query milter states for other event Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_other_event: milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 220 2.0.0 Ready to start TLS Mar 28 10:57:42 dna01 postfix/smtpd[66648]: abort all milters Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_abort: abort milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: auto_clnt_open: connected to private/tlsmgr Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr request = seed Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr size = 32 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: seed Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: seed Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: HIDDEN_BEFORE_POST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: (list terminator) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr request = tktkey Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr keyname = [data 16 bytes] Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 4294967295 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: keybuf Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: keybuf Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: HIDDEN_BEFORE_POST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: (list terminator) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr request = tktkey Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr keyname = [data 0 bytes] Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: keybuf Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: keybuf Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: HIDDEN_BEFORE_POST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: (list terminator) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: Anonymous TLS connection established from talvi.dovecot.org[94.237.25.159]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: name_mask: noanonymous Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: Connecting Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: VERSION?1?1 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: MECH?PLAIN?plaintext Mar 28 10:57:42 dna01 postfix/smtpd[66648]: name_mask: plaintext Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: MECH?LOGIN?plaintext Mar 28 10:57:42 dna01 postfix/smtpd[66648]: name_mask: plaintext Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: SPID?62898 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: CUID?107 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: COOKIE?HIDDEN_BEFORE_POST Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_connect: auth reply: DONE Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_mech_filter: keep mechanism: PLAIN Mar 28 10:57:42 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN Mar 28 10:57:42 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: QUIT Mar 28 10:57:42 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 221 2.0.0 Bye Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 192.168.3.0/24 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 192.168.3.0/24 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 127.0.0.0/8 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 127.0.0.0/8 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr request = disconnect Mar 28 10:57:42 dna01 postfix/smtpd[66648]: send attr ident = smtp:94.237.25.159 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: (list terminator) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:42 dna01 postfix/smtpd[66648]: disconnect event to all milters Mar 28 10:57:42 dna01 postfix/smtpd[66648]: milter8_disc_event: quit milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: disconnect from talvi.dovecot.org[94.237.25.159] ehlo=1 starttls=1 quit=1 commands=3 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: free all milters Mar 28 10:57:42 dna01 postfix/smtpd[66648]: free milter inet:localhost:11332 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: master_notify: status 1 Mar 28 10:57:42 dna01 postfix/smtpd[66648]: connection closed Mar 28 10:57:47 dna01 postfix/smtpd[66648]: auto_clnt_close: disconnect private/tlsmgr stream Mar 28 10:57:55 dna01 postfix/smtpd[66648]: connection established Mar 28 10:57:55 dna01 postfix/smtpd[66648]: master_notify: status 0 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: name_mask: resource Mar 28 10:57:55 dna01 postfix/smtpd[66648]: name_mask: software Mar 28 10:57:55 dna01 postfix/smtpd[66648]: connect from talvi.dovecot.org[94.237.25.159] Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: smtp_stream_setup: maxtime=300 enable_deadline=0 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 192.168.3.0/24 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 192.168.3.0/24 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 127.0.0.0/8 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 127.0.0.0/8 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr request = connect Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr ident = smtp:94.237.25.159 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: count Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: count Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: 1 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: rate Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: rate Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: 2 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: (list terminator) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: report connect to all milters Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "j" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "genome.ku.dk" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{daemon_name}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "genome.ku.dk" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{daemon_addr}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "192.168.3.112" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "v" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: result "Postfix 3.3.3" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: non-protocol events for protocol version 6: Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: transport=inet endpoint=localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: trying... [127.0.0.1] Mar 28 10:57:55 dna01 postfix/smtpd[66648]: vstream_tweak_tcp: TCP_MAXSEG 32741 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: fd=11: stream buffer size old=0 new=65482 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: my_version=0x6 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: milter inet:localhost:11332 version 6 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: events SMFIP_NR_HDR SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_conn_event: milter inet:localhost:11332: connect talvi.dovecot.org/94.237.25.159 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: event: SMFIC_CONNECT; macros: j=genome.ku.dk {daemon_name}=genome.ku.dk {daemon_addr}=192.168.3.112 v=Postfix 3.3.3 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: skipping reply for event SMFIC_CONNECT from milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 220 genome.ku.dk ESMTP Postfix Mar 28 10:57:55 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: EHLO talvi.dovecot.org Mar 28 10:57:55 dna01 postfix/smtpd[66648]: report helo to all milters Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{tls_version}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cipher}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cipher_bits}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cert_subject}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter_macro_lookup: "{cert_issuer}" Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_helo_event: milter inet:localhost:11332: helo talvi.dovecot.org Mar 28 10:57:55 dna01 postfix/smtpd[66648]: event: SMFIC_HELO; macros: (none) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: skipping reply for event SMFIC_HELO from milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-genome.ku.dk Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-PIPELINING Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-SIZE 150000000 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-VRFY Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-ETRN Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-STARTTLS Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-ENHANCEDSTATUSCODES Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250-8BITMIME Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 250 DSN Mar 28 10:57:55 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: STARTTLS Mar 28 10:57:55 dna01 postfix/smtpd[66648]: query milter states for other event Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_other_event: milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 220 2.0.0 Ready to start TLS Mar 28 10:57:55 dna01 postfix/smtpd[66648]: abort all milters Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_abort: abort milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: auto_clnt_open: connected to private/tlsmgr Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr request = seed Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr size = 32 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: seed Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: seed Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: HIDDEN_BEFORE_POST Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/tlsmgr: wanted attribute: (list terminator) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: Anonymous TLS connection established from talvi.dovecot.org[94.237.25.159]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: name_mask: noanonymous Mar 28 10:57:55 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_mech_filter: keep mechanism: PLAIN Mar 28 10:57:55 dna01 postfix/smtpd[66648]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN Mar 28 10:57:55 dna01 postfix/smtpd[66648]: < talvi.dovecot.org[94.237.25.159]: QUIT Mar 28 10:57:55 dna01 postfix/smtpd[66648]: > talvi.dovecot.org[94.237.25.159]: 221 2.0.0 Bye Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 192.168.3.0/24 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 192.168.3.0/24 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostname: smtpd_client_event_limit_exceptions: talvi.dovecot.org ~? 127.0.0.0/8 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_hostaddr: smtpd_client_event_limit_exceptions: 94.237.25.159 ~? 127.0.0.0/8 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: talvi.dovecot.org: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: match_list_match: 94.237.25.159: no match Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr request = disconnect Mar 28 10:57:55 dna01 postfix/smtpd[66648]: send attr ident = smtp:94.237.25.159 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: status Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute value: 0 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: private/anvil: wanted attribute: (list terminator) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: input attribute name: (end) Mar 28 10:57:55 dna01 postfix/smtpd[66648]: disconnect event to all milters Mar 28 10:57:55 dna01 postfix/smtpd[66648]: milter8_disc_event: quit milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: disconnect from talvi.dovecot.org[94.237.25.159] ehlo=1 starttls=1 quit=1 commands=3 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: free all milters Mar 28 10:57:55 dna01 postfix/smtpd[66648]: free milter inet:localhost:11332 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: master_notify: status 1 Mar 28 10:57:55 dna01 postfix/smtpd[66648]: connection closed Mar 28 10:58:00 dna01 postfix/smtpd[66648]: auto_clnt_close: disconnect private/tlsmgr stream -- Christian Anthon

2 2

v2.3.5.1 released
by Aki Tuomi 28 Mar '19

28 Mar '19

https://dovecot.org/releases/2.3/dovecot-2.3.5.1.tar.gz https://dovecot.org/releases/2.3/dovecot-2.3.5.1.tar.gz.sig Binary packages in https://repo.dovecot.org/ * CVE-2019-7524: Missing input buffer size validation leads into arbitrary buffer overflow when reading fts or pop3 uidl header from Dovecot index. Exploiting this requires direct write access to the index files. --- Aki Tuomi Open-Xchange oy

2 2

Panic: file mail-transaction-log-file.c: line 105 (mail_transaction_log_file_free): assertion failed: (!file->locked)
by Arkadiusz Miśkiewicz 28 Mar '19

28 Mar '19

Hello. I have one account with heavy traffic (big mails) and quite often indexes get corrupted. This is dovecot 2.3.5 on local fs (xfs), Linux kernel 4.19.20, glibc 2.28. When corruption happens lmtp and pop3 segfault on accessing it like: > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(24428): Connect from local [0/0] > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Error: Index /var/mail/piast_efaktury/dovecot.index: Lost log for seq=13 offset=25648: Missing middle file seq=13 (between 13..4294967295, we have seqs 14,15): .log.2 contains file_seq=14 (initial_mapped=0, reason=Index mapped) > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Warning: fscking index file /var/mail/piast_efaktury/dovecot.index > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Error: Fixed index file /var/mail/piast_efaktury/dovecot.index: log_file_seq 13 -> 15 > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Panic: file mail-transaction-log-file.c: line 105 (mail_transaction_log_file_free): assertion failed: (!file->locked) > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0xe011b) [0x7f25fc82b11b] -> /usr/lib64/dovecot/libdovecot.so.0(+0xe01b1) [0x7f25fc82b1b1] -> /usr/lib64/dovecot/libdovecot.so.0(+0x4bf56) [0x7f25fc796f56] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x4b17e) [0x7f25fc92f17e] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_logs_clean+0x5c) [0x7f25fc9e6e3c] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_log_close+0x34) [0x7f25fc9e6f04] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_log_move_to_memory+0xed) [0x7f25fc9e709d] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_move_to_memory+0x60) [0x7f25fc9e10b0] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_write+0x1e1) [0x7f25fc9df3a1] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_fsck+0x68a) [0x7f25fc9ca13a] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_sync_map+0x5b0) [0x7f25fc9d4090] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_map+0x13b) [0x7f25fc9cc1eb] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xfcc96) [0x7f25fc9e0c96] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xfd2a7) [0x7f25fc9e12a7] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_open+0x7a) [0x7f25fc9e13aa] -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_storage_mailbox_open+0xac) [0x7f25fc9bac1c] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x84df9) [0x7f25fc968df9] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x84ecf) [0x7f25fc968ecf] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xbe11c) [0x7f25fc9a211c] -> /usr/lib64/dovecot/plugins/lib20_zlib_plugin.so(+0x46ee) [0x7f25f8ff86ee] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x5bd56) [0x7f25fc93fd56] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_open+0x4a) [0x7f25fc93ff3a] -> /usr/lib64/dovecot/libdovecot-lda.so.0(mail_deliver_save_open+0x63) [0x7f25fca49cc3] -> /usr/lib64/dovecot/libdovecot-lda.so.0(mail_deliver_save+0xc9) [0x7f25fca49f29] -> /usr/lib64/dovecot/libdovecot-lda.so.0(mail_deliver+0x1c6) [0x7f25fca4a586] -> dovecot/lmtp [local DATA](lmtp_local_data+0x6a1) [0x55e3e295a551] -> dovecot/lmtp [local DATA](cmd_data_continue+0x25d) [0x55e3e295920d] -> /usr/lib64/dovecot/libdovecot.so.0(+0x65737) [0x7f25fc7b0737] > Mar 27 11:13:50 mbox dovecot[22370]: lmtp(piast_efaktury): pid=<24428> session=<QLacCN5Mm1xsXwAA9fPEKQ>, Fatal: master: service(lmtp): child 24428 killed with signal 6 (core dumped) > ~ lmtp backtrace: http://ixion.pld-linux.org/~arekm/dovecot/lmtp-gdb.txt log: http://ixion.pld-linux.org/~arekm/dovecot/lmtp.txt pop3 backtrace: http://ixion.pld-linux.org/~arekm/dovecot/pop3-gdb.txt log: http://ixion.pld-linux.org/~arekm/dovecot/pop3.txt deleting dovecot.index* helps until problem starts again like - first entry with problem after deleting indexes: > Mar 26 14:18:12 mbox dovecot[10001]: pop3-login: Login: user=<piast_efaktury>, method=PLAIN, rip=1.1.1.1, lip=2.2.2.2, mpid=5694, session=</YwtJ/+EZPG5sziF> > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Error: Index /var/mail/piast_efaktury/dovecot.index: Lost log for seq=13 offset=25648: Missing middle file seq=13 (between 13..4294967295, we have seqs 14,15): .log.2 contains file_seq=14 (initial_mapped=0, reason=Index mapped) > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Warning: fscking index file /var/mail/piast_efaktury/dovecot.index > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Error: Fixed index file /var/mail/piast_efaktury/dovecot.index: log_file_seq 13 -> 15 > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Panic: file mail-transaction-log-file.c: line 105 (mail_transaction_log_file_free): assertion failed: (!file->locked) > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0xe011b) [0x7f20b6e2911b] -> /usr/lib64/dovecot/libdovecot.so.0(+0xe01b1) [0x7f20b6e291b1] -> /usr/lib64/dovecot/libdovecot.so.0(+0x4bf56) [0x7f20b6d94f56] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x4b17e) [0x7f20b6f2d17e] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_logs_clean+0x5c) [0x7f20b6fe4e3c] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_log_close+0x34) [0x7f20b6fe4f04] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_transaction_log_move_to_memory+0xed) [0x7f20b6fe509d] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_move_to_memory+0x60) [0x7f20b6fdf0b0] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_write+0x1e1) [0x7f20b6fdd3a1] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_fsck+0x68a) [0x7f20b6fc813a] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_sync_map+0x5b0) [0x7f20b6fd2090] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_map+0x13b) [0x7f20b6fca1eb] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xfcc96) [0x7f20b6fdec96] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xfd2a7) [0x7f20b6fdf2a7] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_index_open+0x7a) [0x7f20b6fdf3aa] -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_storage_mailbox_open+0xac) [0x7f20b6fb8c1c] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x84df9) [0x7f20b6f66df9] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x84ecf) [0x7f20b6f66ecf] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0xbe11c) [0x7f20b6fa011c] -> /usr/lib64/dovecot/plugins/lib20_zlib_plugin.so(+0x46ee) [0x7f20b36896ee] -> /usr/lib64/dovecot/libdovecot-storage.so.0(+0x5bd56) [0x7f20b6f3dd56] -> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_open+0x4a) [0x7f20b6f3df3a] -> dovecot/pop3 [piast_efaktury 1.1.1.1](client_init_mailbox+0x7a) [0x5638a04d1bda] -> dovecot/pop3 [piast_efaktury 1.1.1.1](+0x5645) [0x5638a04d0645] -> dovecot/pop3 [piast_efaktury 1.1.1.1](+0x5882) [0x5638a04d0882] -> /usr/lib64/dovecot/libdovecot.so.0(+0x74021) [0x7f20b6dbd021] -> /usr/lib64/dovecot/libdovecot.so.0(+0x7439b) [0x7f20b6dbd39b] -> /usr/lib64/dovecot/libdovecot.so.0(+0x74d1d) [0x7f20b6dbdd1d] > Mar 26 14:18:12 mbox dovecot[10001]: pop3(piast_efaktury): pid=<5694> session=</YwtJ/+EZPG5sziF>, Fatal: master: service(pop3): child 5694 killed with signal 6 (core dumps disabled - https://dovecot.org/bugreport.html#coredumps) dovecot isn't able to auto fix the indexes and manual deletion is required in all such cases -- Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )

2 5