January 2022 - dovecot

Dovecot 2.3.17 on FreeBSD 12.2 panic
by Bert JW Regeer 10 Jan '22

10 Jan '22

Hello, I have dovecot 2.3.17 running on FreeBSD 12.2 and it keeps panicking: Jan 10 03:04:07 strida dovecot[55198]: imap(xistence(a)0x58.com)<56382><dx4KlzHVQecmAQKCQwA50VytdgLnsQSr>: Panic: file array.c: line 10 (array_idx_modifiable_i): assertion failed: (idx < array->buffer->used / array->element_size) Jan 10 03:04:07 strida dovecot[55198]: imap(xistence(a)0x58.com)<56382><dx4KlzHVQecmAQKCQwA50VytdgLnsQSr>: Fatal: master: service(imap): child 56382 killed with signal 6 (core not dumped - https://dovecot.org/bugreport.html#coredumps) Ignore the core not dumped, this is happening over and over, and I got one process to core dump: # lldb /usr/local/libexec/dovecot/imap -c imap.core (lldb) target create "/usr/local/libexec/dovecot/imap" --core "imap.core" Core file '/usr/local/vmail/domains/0x58.com/xistence/imap.core' (x86_64) was loaded. (lldb) bt * thread #1, name = 'imap', stop reason = signal SIGABRT * frame #0: 0x0000000011588c2a libc.so.7`__sys_thr_kill + 10 frame #1: 0x0000000011587084 libc.so.7`__raise + 52 frame #2: 0x00000000114fd279 libc.so.7`abort + 73 frame #3: 0x00000000113736f3 libdovecot.so.0`___lldb_unnamed_symbol873$$libdovecot.so.0 + 147 frame #4: 0x0000000011371eaf libdovecot.so.0`___lldb_unnamed_symbol862$$libdovecot.so.0 + 47 frame #5: 0x0000000011372c71 libdovecot.so.0`___lldb_unnamed_symbol864$$libdovecot.so.0 + 33 frame #6: 0x00000000113720bb libdovecot.so.0`i_panic + 187 frame #7: 0x0000000011363d3f libdovecot.so.0`array_idx_modifiable_i + 79 frame #8: 0x0000000011ef7c68 lib20_fts_plugin.so`fts_user_autoindex_exclude + 72 frame #9: 0x0000000011ef550f lib20_fts_plugin.so`fts_mailbox_allocated + 239 frame #10: 0x000000001113ed5a libdovecot-storage.so.0`hook_mailbox_allocated + 154 frame #11: 0x00000000111381e1 libdovecot-storage.so.0`mailbox_alloc + 449 frame #12: 0x0000000001043db4 imap`cmd_select_full + 356 frame #13: 0x000000000104c582 imap`command_exec + 178 frame #14: 0x000000000104ae8a imap`___lldb_unnamed_symbol58$$imap + 58 frame #15: 0x000000000104af91 imap`___lldb_unnamed_symbol58$$imap + 321 frame #16: 0x00000000010499e7 imap`client_handle_input + 471 frame #17: 0x0000000001048178 imap`client_input + 120 frame #18: 0x000000001138ca9f libdovecot.so.0`io_loop_call_io + 111 frame #19: 0x000000001138f45b libdovecot.so.0`io_loop_handler_run_internal + 347 frame #20: 0x000000001138cffa libdovecot.so.0`io_loop_handler_run + 346 frame #21: 0x000000001138ce58 libdovecot.so.0`io_loop_run + 88 frame #22: 0x00000000112f11c8 libdovecot.so.0`master_service_run + 24 frame #23: 0x000000000105a417 imap`main + 1383 frame #24: 0x000000000103bed2 imap`_start + 226 (lldb) ^D I was able to generate a core dump by issue a doveadm command too: (lldb) bt * thread #1, name = 'doveadm', stop reason = signal SIGABRT * frame #0: 0x00000008017b1c2a libc.so.7`__sys_thr_kill + 10 frame #1: 0x00000008017b0084 libc.so.7`__raise + 52 frame #2: 0x0000000801726279 libc.so.7`abort + 73 frame #3: 0x000000080159c6f3 libdovecot.so.0`___lldb_unnamed_symbol873$$libdovecot.so.0 + 147 frame #4: 0x000000080159aeaf libdovecot.so.0`___lldb_unnamed_symbol862$$libdovecot.so.0 + 47 frame #5: 0x000000080159ae71 libdovecot.so.0`default_fatal_handler + 33 frame #6: 0x000000080159b0bb libdovecot.so.0`i_panic + 187 frame #7: 0x000000080158cd3f libdovecot.so.0`array_idx_modifiable_i + 79 frame #8: 0x0000000802236c68 lib20_fts_plugin.so`fts_user_autoindex_exclude + 72 frame #9: 0x000000080223450f lib20_fts_plugin.so`fts_mailbox_allocated + 239 frame #10: 0x0000000801367d5a libdovecot-storage.so.0`hook_mailbox_allocated + 154 frame #11: 0x00000008013611e1 libdovecot-storage.so.0`mailbox_alloc + 449 frame #12: 0x000000080222d5fc lib20_fts_plugin.so`fts_backend_rescan + 60 frame #13: 0x000000080227c1a3 lib20_doveadm_fts_plugin.so`___lldb_unnamed_symbol15$$lib20_doveadm_fts_plugin.so + 99 frame #14: 0x000000000107172f doveadm`___lldb_unnamed_symbol134$$doveadm + 479 frame #15: 0x000000000107252c doveadm`doveadm_cmd_ver2_to_mail_cmd_wrapper + 2492 frame #16: 0x0000000001083c98 doveadm`doveadm_cmd_run_ver2 + 1416 frame #17: 0x00000000010836d7 doveadm`doveadm_cmd_try_run_ver2 + 71 frame #18: 0x0000000001086da3 doveadm`main + 835 frame #19: 0x000000000105fa92 doveadm`_start + 226 (lldb) # doveadm fts rescan -u xistence(a)0x58.com doveadm(xistence(a)0x58.com): Panic: file array.c: line 10 (array_idx_modifiable_i): assertion failed: (idx < array->buffer->used / array->element_size) Abort (core dumped) # dovecot-sysreport Gathering configurations ... grep: The -P option is not supported grep: The -P option is not supported grep: The -P option is not supported Gathering system informations ... Creating archive ... All done! Please report file dovecot-sysreport-strida.0x58.com-1641784164.tar.gz Removing temp files at /tmp/tmp.z5qJkwrW … While reading about fts/fts_squat I came across the page noting it was deprecated. I am running a mail server for myself, and have avoided installing Solr this entire time, but I guess its time to upgrade. In the mean time hopefully this core dump can help figure out what is going on. Bert JW Regeer

2 3

outlook 2019 not working
by postmaster 10 Jan '22

10 Jan '22

Just tried connecting a Windows 10 client with Outlook 2019 but it fail's on both POP3 or IMAP - i knew it was working when i tested it after the server setup about a year ago because i documented everything with screenshots. All other devices we use (Thunderbird, iPhone/iPad, Android devices, RoundCube) are working without any issue, just Outlook won't connect anymore. We don't have much Windows/Outlook experience - any help/hints appreciated. This what i have in the logs, but doesn't see anything that helps: 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x10, ret=1: before SSL initialization 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client hello 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server hello 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write certificate 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write key exchange 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client key exchange 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read change cipher spec 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read finished 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write session ticket 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write change cipher spec 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write finished 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully 2022.01.10 02:22:25 pop3-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully 2022.01.10 02:22:25 pop3-login: Info: Login: user=<user1(a)mail-server.cc>, method=PLAIN, rip=178.189.103.34, lip=195.88.238.13, mpid=1694, TLS, TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Loading modules from directory: /usr/lib/dovecot/modules 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_virtual_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_zlib_plugin.so 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=10240000 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Effective uid=5000, gid=5000, home=/srv/vmail/mail-server.cc/user1/ 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(file): dict created (uri=file:/srv/vmail/shared-mailboxes.db, base_dir=/var/run/dovecot) 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota root: name=User Quota backend=dict args=:proxy::sqluserquota 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota rule: root=User Quota mailbox=* bytes=10240000 messages=0 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota rule: root=User Quota mailbox=Trash bytes=+1024000 (10%) messages=0 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota rule: root=User Quota mailbox=Sent bytes=+1024000 (10%) messages=0 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota warning: bytes=10240000 (100%) messages=0 reverse=no command=quota-warning 100 user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota warning: bytes=9728000 (95%) messages=0 reverse=no command=quota-warning 95 user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota warning: bytes=9216000 (90%) messages=0 reverse=no command=quota-warning 90 user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota warning: bytes=8192000 (80%) messages=0 reverse=no command=quota-warning 80 user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Quota grace: root=User Quota bytes=1024000 (10%) 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: quota-dict: user=user1(a)mail-server.cc, uri=proxy::sqluserquota, noenforcing=0 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(proxy): dict created (uri=proxy::sqluserquota, base_dir=/var/run/dovecot) 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/srv/vmail/mail-server.cc/user1/maildir 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: maildir++: root=/srv/vmail/mail-server.cc/user1/maildir, index=, indexpvt=, control=, inbox=/srv/vmail/mail-server.cc/user1/maildir,alt= 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: initializing backend with data: vfile 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: acl username = user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: owner = 1 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl vfile: Global ACLs disabled 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Namespace : type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:/srv/vmail/%d/%n/maildir:INDEX=~/maildir/shared/%u:CONTROL=~/maildir/shared/%u 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: shared: root=/var/run/dovecot, index=, indexpvt=, control=, inbox=, alt= 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: initializing backend with data: vfile 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: acl username = user1(a)mail-server.cc 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl: owner = 0 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl vfile: Global ACLs disabled 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: Mailbox INBOX: Mailbox opened because: POP3 INBOX 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: acl vfile: file /srv/vmail/mail-server.cc/user1/maildir/dovecot-acl not found 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0, bytes=12/43 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(proxy): Waiting for dict to finish pending operations 2022.01.10 02:22:25 pop3-login: Debug: SSL alert: close notify 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(file): dict destroyed 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(proxy): Waiting for dict to finish pending operations 2022.01.10 02:22:25 pop3(user1(a)mail-server.cc)<1694><jsRYKzDVCMSyvWci>: Debug: dict(proxy): dict destroyed 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x10, ret=1: before SSL initialization 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client hello 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server hello 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write certificate 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write key exchange 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client key exchange 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read change cipher spec 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read finished 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write session ticket 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write change cipher spec 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write finished 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully 2022.01.10 02:23:00 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully 2022.01.10 02:23:00 imap-login: Info: Login: user=<user1(a)mail-server.cc>, method=PLAIN, rip=178.189.103.34, lip=195.88.238.13, mpid=1696, TLS, TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Loading modules from directory: /usr/lib/dovecot/modules 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_virtual_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_zlib_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=10240000 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Effective uid=5000, gid=5000, home=/srv/vmail/mail-server.cc/user1/ 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: dict(file): dict created (uri=file:/srv/vmail/shared-mailboxes.db, base_dir=/var/run/dovecot) 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota root: name=User Quota backend=dict args=:proxy::sqluserquota 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota rule: root=User Quota mailbox=* bytes=10240000 messages=0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota rule: root=User Quota mailbox=Trash bytes=+1024000 (10%) messages=0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota rule: root=User Quota mailbox=Sent bytes=+1024000 (10%) messages=0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota warning: bytes=10240000 (100%) messages=0 reverse=no command=quota-warning 100 user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota warning: bytes=9728000 (95%) messages=0 reverse=no command=quota-warning 95 user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota warning: bytes=9216000 (90%) messages=0 reverse=no command=quota-warning 90 user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota warning: bytes=8192000 (80%) messages=0 reverse=no command=quota-warning 80 user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Quota grace: root=User Quota bytes=1024000 (10%) 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: quota-dict: user=user1(a)mail-server.cc, uri=proxy::sqluserquota, noenforcing=0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: dict(proxy): dict created (uri=proxy::sqluserquota, base_dir=/var/run/dovecot) 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/srv/vmail/mail-server.cc/user1/maildir 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: maildir++: root=/srv/vmail/mail-server.cc/user1/maildir, index=, indexpvt=, control=, inbox=/srv/vmail/mail-server.cc/user1/maildir,alt= 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: initializing backend with data: vfile 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: acl username = user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: owner = 1 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl vfile: Global ACLs disabled 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: Namespace : type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:/srv/vmail/%d/%n/maildir:INDEX=~/maildir/shared/%u:CONTROL=~/maildir/shared/%u 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: shared: root=/var/run/dovecot, index=, indexpvt=, control=, inbox=, alt= 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: initializing backend with data: vfile 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: acl username = user1(a)mail-server.cc 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl: owner = 0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl vfile: Global ACLs disabled 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping 2022.01.10 02:23:00 imap-login: Debug: SSL error: Connection closed 2022.01.10 02:23:00 imap-login: Debug: SSL alert: close notify 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: acl vfile: file /srv/vmail/mail-server.cc/user1/maildir/dovecot-acl not found 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Info: Disconnected: Connection closed (IDLE running for 0.001 + waiting input for 0.001 secs, 2 B in + 10 B out, state=wait-input) in=11 out=461 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: dict(file): dict destroyed 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: dict(proxy): Waiting for dict to finish pending operations 2022.01.10 02:23:00 imap(user1(a)mail-server.cc)<1696><S1ptLTDVEcSyvWci>: Debug: dict(proxy): dict destroyed thx, Alex

2 1

Patch: assertion failed in doveadm fts lookup
by John Fawcett 09 Jan '22

09 Jan '22

Hi I'm reposting this patch, which I have been applying locally since I originally posted it. Hopefully it can be considered for inclusion in the official release. It was tested on dovecot 2.3.16 but applies against the latest version 2.3.17.1. This is the "assertion failed" that it addresses doveadm fts lookup -u john(a)voipsupport.it body "text to look for" doveadm(john(a)voipsupport.it): Panic: file mail-storage.c: line 2108 (mailbox_get_open_status): assertion failed: (box->opened) doveadm(john(a)voipsupport.it): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0(backtrace_append+0x42) [0x7ff624fa7072] -> /usr/local/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7ff624fa718e] -> /usr/local/lib/dovecot/libdovecot.so.0(+0xffc3b) [0x7ff624fb3c3b] -> /usr/local/lib/dovecot/libdovecot.so.0(+0xffc71) [0x7ff624fb3c71] -> /usr/local/lib/dovecot/libdovecot.so.0(+0x5536f) [0x7ff624f0936f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x3fc31) [0x7ff6250bcc31] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so(+0x540d) [0x7ff62244f40d] -> /usr/local/lib/dovecot/lib20_fts_plugin.so(fts_backend_lookup+0x4d) [0x7ff6246b624d] -> /usr/local/lib/dovecot/doveadm/lib20_doveadm_fts_plugin.so(+0x2e8c) [0x7ff62240ce8c] -> doveadm(+0x31ded) [0x55f0c7f3aded] -> doveadm(+0x32862) [0x55f0c7f3b862] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x22d) [0x55f0c7f3c6fd] -> doveadm(doveadm_cmd_run_ver2+0x4d8) [0x55f0c7f4d158] -> doveadm(doveadm_cmd_try_run_ver2+0x3a) [0x55f0c7f4d1aa] -> doveadm(main+0x1f6) [0x55f0c7f2b606] -> /lib64/libc.so.6(__libc_start_main+0xd5) [0x7ff624bc8b75] -> doveadm(_start+0x2e) [0x55f0c7f2ba0e] Aborted (core dumped) Here's the patch: diff -ur dovecot-2.3.17.1-orig/src/plugins/fts/doveadm-fts.c dovecot-2.3.17.1-new/src/plugins/fts/doveadm-fts.c --- dovecot-2.3.17.1-orig/src/plugins/fts/doveadm-fts.c 2021-12-03 12:48:47.000000000 +0100 +++ dovecot-2.3.17.1-new/src/plugins/fts/doveadm-fts.c 2022-01-09 01:33:23.396342025 +0100 @@ -47,6 +47,14 @@ i_array_init(&result.scores, 16); box = mailbox_alloc(info->ns->list, info->vname, 0); + mailbox_set_reason(box,"fts search"); + if (mailbox_open(box) < 0) { + i_error("Couldn't open mailbox: %s", + mailbox_get_last_internal_error(box, NULL)); + doveadm_mail_failed_error(ctx, MAIL_ERROR_TEMP); + return -1; + } + if (fts_backend_lookup(backend, box, ctx->search_args->args, FTS_LOOKUP_FLAG_AND_ARGS, &result) < 0) { i_error("fts lookup failed"); John

2 1

Non-user logins?
by Ken Wright 09 Jan '22

09 Jan '22

My Dovecot issues continue. Right now I see at least two issues: first, my logs consistently show non-users trying (and failing) to log in, and I'm still unable to log in from my email client (Evolution or Roundcube, either one). I'll post about the second issue later; right now I wonder why I'm getting so many non-users trying to log in. Am I the subject of concerted hacking attacks, or is there something else going on? Some of the attempted logins are more-or-less random names claiming to be @mydomain, but at least one is a username that's really on my server, to wit: Jan 7 22:52:01 grace dovecot: lmtp(776281): Error: lmtp-server: conn unix:pid=776262,uid=117 [3]: rcpt www-data(a)mydomain.com: Failed to lookup user www-data(a)mydomain.com: Internal error occurred. Refer to server log for more information. (Another quick question: which server log should I check?) So, if anyone can tell me what's going on with all these logins, I'd be much obliged! Ken

9 16

Patch: enhancements for solr/tika integration
by John Fawcett 09 Jan '22

09 Jan '22

Hi here's a patch with some enhancements that I am applying locally for solr/tika integration. Hopefully this can be considered for inclusion. I've tested up to 2.3.16 and this patch applies against latest version 2.3.17.1. The contents are: 1. Allow username and password in tika configuration (as is already supported for solr). For example: fts_tika = https://user:password@tika_host:tika_port/tika/tika This means that tika can be more easily located on a different server to dovecot. Locating Solr and Tika on separate servers can isolate the Dovecot server from issues that may happen on Solr or Tika (like out of memory). 2. Introduce an optional configurable limit on the size of emails whose message bodies will be indexed with solr via a new setting fts_max_size, to be put in the plugin section. For example plugin { ... fts_max_size = 2M ... } Message body indexing is skipped for messages that are larger than this setting. 3. Introduce an optional configurable limit on the size of emails whose attachments will be sent to tika for keyword extraction, via a new setting fts_max_size_tika, to be put in the plugin section. For example: plugin { ... fts_max_size_tika = 1M } I noticed that some very large attachments are being sent to tika and these often do not have any useful content to index. For simplicity the check is done on message size not individual or total attachment size. Here's the patch: diff -ur dovecot-2.3.17.1-orig/src/plugins/fts/fts-build-mail.c dovecot-2.3.17.1-new/src/plugins/fts/fts-build-mail.c --- dovecot-2.3.17.1-orig/src/plugins/fts/fts-build-mail.c 2021-12-03 12:48:47.000000000 +0100 +++ dovecot-2.3.17.1-new/src/plugins/fts/fts-build-mail.c 2022-01-09 01:33:23.398341998 +0100 @@ -17,6 +17,7 @@ #include "fts-filter.h" #include "fts-api-private.h" #include "fts-build-mail.h" +#include "settings-parser.h" /* there are other characters as well, but this doesn't have to be exact */ #define IS_WORD_WHITESPACE(c) \ @@ -25,6 +26,8 @@ wherever */ #define MAX_WORD_SIZE 1024 +static bool debug = FALSE; + struct fts_mail_build_context { struct mail *mail; struct fts_backend_update_context *update_ctx; @@ -34,6 +37,7 @@ buffer_t *word_buf, *pending_input; struct fts_user_language *cur_user_lang; + bool oversized_tika; }; static int fts_build_data(struct fts_mail_build_context *ctx, @@ -223,7 +227,7 @@ parser_context.user = mail_storage_get_user(storage); parser_context.content_disposition = ctx->content_disposition; - + parser_context.oversized_tika = ctx->oversized_tika; if (fts_parser_init(&parser_context, &ctx->body_parser)) { /* extract text using the the returned parser */ *binary_body_r = TRUE; @@ -496,7 +500,32 @@ bool binary_body; const char *error; int ret; - + uoff_t msg_size; + uoff_t fts_max_size = 0; + uoff_t fts_max_size_tika = 0; + const char * fts_max_size_setting; + const char * fts_max_size_tika_setting; + bool oversized_msg; + bool oversized_tika; + + fts_max_size_setting = mail_user_plugin_getenv(update_ctx->backend->ns->user, "fts_max_size"); + if (fts_max_size_setting != NULL) { + if (debug) i_debug("fts_max_size %s",fts_max_size_setting); + if (settings_get_size(fts_max_size_setting, &fts_max_size, &error) < 0) { + i_error("%s",error); + fts_max_size = 0; + } + if (debug) i_debug("fts_max_size (value) %"PRIuUOFF_T,fts_max_size); + } + fts_max_size_tika_setting = mail_user_plugin_getenv(update_ctx->backend->ns->user, "fts_max_size_tika"); + if (fts_max_size_tika_setting != NULL) { + if (debug) i_debug("fts_max_size_tika %s",fts_max_size_tika_setting); + if (settings_get_size(fts_max_size_tika_setting, &fts_max_size_tika, &error) < 0) { + i_error("%s",error); + fts_max_size_tika = 0; + } + if (debug) i_debug("fts_max_size_tika (value) %"PRIuUOFF_T,fts_max_size_tika); + } *may_need_retry_r = FALSE; if (mail_get_stream_because(mail, NULL, NULL, "fts indexing", &input) < 0) { if (mail->expunged) @@ -505,10 +534,21 @@ mailbox_get_last_internal_error(mail->box, NULL)); return -1; } - + oversized_msg = FALSE; + oversized_tika = FALSE; + i_stream_get_size(input,TRUE,&msg_size); + if (fts_max_size > 0 && msg_size > fts_max_size) { + i_info("Skipping message body indexing because size %"PRIuUOFF_T" exceeds setting fts_max_size %s",msg_size,fts_max_size_setting); + oversized_msg = TRUE; + } + if (fts_max_size_tika > 0 && msg_size > fts_max_size_tika) { + i_info("Skipping message attachment indexing because size %"PRIuUOFF_T" exceeds setting fts_max_size_tika %s",msg_size,fts_max_size_tika_setting); + oversized_tika = TRUE; + } i_zero(&ctx); ctx.update_ctx = update_ctx; ctx.mail = mail; + ctx.oversized_tika = oversized_tika; if ((update_ctx->backend->flags & FTS_BACKEND_FLAG_TOKENIZED_INPUT) != 0) ctx.pending_input = buffer_create_dynamic(default_pool, 128); @@ -563,7 +603,7 @@ message_decoder_set_return_binary(decoder, TRUE); body_part = TRUE; } else { - if (skip_body) + if (skip_body ||oversized_msg) continue; } @@ -597,7 +637,7 @@ else (void)fts_parser_deinit(&ctx.body_parser, NULL); } - if (ret == 0 && body_part && !skip_body && !body_added) { + if (ret == 0 && body_part && !skip_body && !oversized_msg && !body_added) { /* make sure body is added even when it doesn't exist */ block.data = NULL; block.size = 0; ret = fts_build_body_block(&ctx, &block, TRUE); diff -ur dovecot-2.3.17.1-orig/src/plugins/fts/fts-parser.h dovecot-2.3.17.1-new/src/plugins/fts/fts-parser.h --- dovecot-2.3.17.1-orig/src/plugins/fts/fts-parser.h 2021-12-03 12:48:47.000000000 +0100 +++ dovecot-2.3.17.1-new/src/plugins/fts/fts-parser.h 2022-01-09 01:33:23.399341985 +0100 @@ -10,6 +10,7 @@ /* Can't be NULL */ const char *content_type; const char *content_disposition; + bool oversized_tika; }; struct fts_parser_vfuncs { diff -ur dovecot-2.3.17.1-orig/src/plugins/fts/fts-parser-tika.c dovecot-2.3.17.1-new/src/plugins/fts/fts-parser-tika.c --- dovecot-2.3.17.1-orig/src/plugins/fts/fts-parser-tika.c 2021-12-03 12:48:47.000000000 +0100 +++ dovecot-2.3.17.1-new/src/plugins/fts/fts-parser-tika.c 2022-01-09 01:33:23.400341972 +0100 @@ -57,7 +57,7 @@ tuser = p_new(user->pool, struct fts_parser_tika_user, 1); MODULE_CONTEXT_SET(user, fts_parser_tika_user_module, tuser); - if (http_url_parse(url, NULL, 0, user->pool, + if (http_url_parse(url, NULL, HTTP_URL_ALLOW_USERINFO_PART, user->pool, &tuser->http_url, &error) < 0) { i_error("fts_tika: Failed to parse HTTP url %s: %s", url, error); return -1; @@ -148,6 +148,10 @@ if (tika_get_http_client_url(parser_context->user, &http_url) < 0) return NULL; + if (parser_context->oversized_tika) { + i_info("skipping tika parser due to oversized message"); + return NULL; + } if (http_url->path == NULL) http_url->path = "/"; @@ -159,6 +163,11 @@ http_url->host.name, t_strconcat(http_url->path, http_url->enc_query, NULL), fts_tika_parser_response, parser); + if (http_url->user != NULL) { + http_client_request_set_auth_simple( + http_req, http_url->user, http_url->password); + } + http_client_request_set_port(http_req, http_url->port); http_client_request_set_ssl(http_req, http_url->have_ssl); if (parser_context->content_type != NULL) John

1 0

Patch: safeguard against too large value for uid being sent to solr for single mailbox searches
by John Fawcett 09 Jan '22

09 Jan '22

Hi I'm reposting a patch for solr integration which I have been applying locally. It applies against 2.3.17.1. Dovecot already has a mechanism when doing solr fts searches on multiple mailboxes that prevents a too large value for maximum rows being sent to solr. #define SOLR_MAX_MULTI_ROWS 100000 (defined and used in plugins/fts-solr/fts-backend-solr.c) However on single mailbox searches Dovecot uses the last uid of the mailbox, which can be too large for solr. My suggested patch is to also limit maximum rows to return on single mailbox searches. Here is the patch: diff -ur dovecot-2.3.17.1-orig/src/plugins/fts-solr/fts-backend-solr.c dovecot-2.3.17.1-new/src/plugins/fts-solr/fts-backend-solr.c --- dovecot-2.3.17.1-orig/src/plugins/fts-solr/fts-backend-solr.c 2021-12-03 12:48:47.000000000 +0100 +++ dovecot-2.3.17.1-new/src/plugins/fts-solr/fts-backend-solr.c 2022-01-09 01:33:23.401341959 +0100 @@ -837,7 +837,7 @@ str = t_str_new(256); str_printfa(str, "wt=xml&fl=uid,score&rows=%u&sort=uid+asc&q=%%7b!lucene+q.op%%3dAND%%7d", - status.uidnext); + I_MIN(status.uidnext,SOLR_MAX_MULTI_ROWS)); prefix_len = str_len(str); if (solr_add_definite_query_args(str, args, and_args)) { John

1 0

Can't log in from Evolution or Roundcube
by Ken Wright 09 Jan '22

09 Jan '22

When I try to log in to my mail server (ubuntu 20.04, Postfix 3.4.13, Dovecot 2.3.7.2) I get a response saying "Source stream returned no data”. At least to me, that's not particularly informative. Is it any more informative to anyone else? Ken

3 10

Sv: banning
by Sebastian Nielsen 08 Jan '22

08 Jan '22

I would say, lock accounts to for example IP address, ASN or GeoIP. This can be accomplished simply by a custom login handler, which also checks IP against database. And first time users, and those who change country/ISP/IP have to simply logon to a web interface (where 2FA can be required and also Captcha) and add their IPs/ASNs/Geo's. For a larger user base, I would recommend GeoIP and no web interface, save country of first login to database, and subsequent logins must originate from same country. Users that want to reset have to contact support. If you are a web hotel who only sell service to a specific country at all, lock the ports in firewall to that GeoIP. For smaller user base, like 50-100 users, I would recommend locking to ASN and providing a web interface where multiple ASN can be added. So people syncing from mobile and home can succeed. For very small user base, like 10's of users, just plan lock to IP. By connecting IP to accounts, you greatly reduce the attack surface.

1 0

TLS connection closed unexpectedly
by Ken Wright 08 Jan '22

08 Jan '22

I reinstalled Dovecot this evening, because I haven't been able to receive emails recently. After configuring and adjusting for the use of PostfixAdmin, I get the following error message in Evolution:; Failed to open folder. The reported error was "Failed to authenticate: TLS connection closed unexpectedly". Does anyone recognize this error? Ken

6 8

Update from 2.3.16 to 2.3.17 Received invalid SSL certificate: unable to get certificate CRL
by Salatiel Filho 08 Jan '22

08 Jan '22

Hi, after updating from dovecot.x86_64 2:2.3.16-2 to 2:2.3.17.1-1 on AlmaLinux 8 my dovecot replication stopped working. Log is full of Error: doveadm server disconnected before handshake: Received invalid SSL certificate: unable to get certificate CRL: /CN=my.domain.redacted (check ssl_client_ca_* settings?) No configuration has changed on my side. My certificate is a wildcard certificate ( not sure if related ). I am also replicating over tcps. Anyone else facing this issue? Atenciosamente/Kind regards, Salatiel

1 0