January 2021 - dovecot

fts_solr: Indexing failed (fails on particular messages/mailboxes by timeout)
by Alexey Panov 18 Jan '21

18 Jan '21

Hello, I am running recent dovecot 2.3.13 (89f716dc2) within dockerized mailcow setup. During just another update routine I decided to reindex all mailboxes and some of them fail (timeout) on exactly SAME messages in SAME mailboxes: > doveadm(u@d): Error: fts_solr: Indexing failed: Request timed out (Request queued 73.213 secs ago, 1 send attempts in 73.098 secs, 60.597 in http ioloop, 0.000 in other ioloops, connected 127.875 secs ago) > doveadm(u@d): Error: Mailbox Sent: Mail search failed: Internal error occurred. Refer to server log for more information. [2021-01-14 11:23:46] > doveadm(u@d): Error: Mailbox Sent: Transaction commit failed: FTS transaction commit failed: backend deinit This error is persistent and affects only some, but always same folders of same mailboxes (i mean solr can't finish indexing them at all). I/O is in perfect condition and has no corruptions. I also tried to do fts rescan which made no change. RAM is fine, I haven't seen OOM conditions. During my research I found this discussion <https://www.mail-archive.com/dovecot@dovecot.org/msg76944.html> which lead me idea of reducing the batch_size to as low as 10 (for testing purposes). Observing SOLR logs during reindexing on the mailbox/folder causing the error I noticed the following strange behaviour. Firstly, it goes very fast but then always kinda freezes on these messages: > solr-mailcow_1 | 2021-01-14 16:05:09.615 INFO (qtp524223214-1151) [ x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts] webapp=/solr path=/update params={}{add=[6883/78a0ec27b091da5e4054000013681708/u@d (1688878773188952064), 6884/78a0ec27b091da5e4054000013681708/u@d (1688878773203632128), 6885/78a0ec27b091da5e4054000013681708/u@d (1688878773218312192), 6886/78a0ec27b091da5e4054000013681708/u@d (1688878773227749376), 6887/78a0ec27b091da5e4054000013681708/u@d (1688878773237186560), 6888/78a0ec27b091da5e4054000013681708/u@d (1688878773244526592), 6889/78a0ec27b091da5e4054000013681708/u@d (1688878773250818048), 6890/78a0ec27b091da5e4054000013681708/u@d (1688878773259206656), 6891/78a0ec27b091da5e4054000013681708/u@d (1688878773272838144), 6892/78a0ec27b091da5e4054000013681708/u@d (1688878773288566784)]} 0 101 > solr-mailcow_1 | 2021-01-14 16:06:42.540 INFO (qtp524223214-1143) [ x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts] webapp=/solr path=/update params={}{add=[6893/78a0ec27b091da5e4054000013681708/u@d (1688878773329461248), 6894/78a0ec27b091da5e4054000013681708/u@d (1688878773332606976), 6895/78a0ec27b091da5e4054000013681708/u@d (1688878774361260032), 6896/78a0ec27b091da5e4054000013681708/u@d (1688878850290745344), 6897/78a0ec27b091da5e4054000013681708/u@d (1688878851347709952), 6898/78a0ec27b091da5e4054000013681708/u@d (1688878852404674560), 6899/78a0ec27b091da5e4054000013681708/u@d (1688878853586419712), 6900/78a0ec27b091da5e4054000013681708/u@d (1688878870704422912), 6901/78a0ec27b091da5e4054000013681708/u@d (1688878870709665792), 6902/78a0ec27b091da5e4054000013681708/u@d (1688878870727491584)]} 0 92891 It takes almost one and a half minute to get those ten messages (6893-6902) indexed. It freezes exactly on that position every time I restart indexing. Actually only reducing the batch_size to 10 made it through. It was timing out with the default batch_size exactly here each time. Than it goes further again blazing fast until it reaches here: > solr-mailcow_1 | 2021-01-14 16:07:26.148 INFO (qtp524223214-1151) [ x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts] webapp=/solr path=/update params={}{add=[7443/78a0ec27b091da5e4054000013681708/u@d (1688878884286627840), 7444/78a0ec27b091da5e4054000013681708/u@d (1688878884293967872), 7445/78a0ec27b091da5e4054000013681708/u@d (1688878884304453632), 7446/78a0ec27b091da5e4054000013681708/u@d (1688878884502634496), 7447/78a0ec27b091da5e4054000013681708/u@d (1688878900331937792), 7448/78a0ec27b091da5e4054000013681708/u@d (1688878900508098560), 7449/78a0ec27b091da5e4054000013681708/u@d (1688878916409753600), 7450/78a0ec27b091da5e4054000013681708/u@d (1688878916424433664), 7451/78a0ec27b091da5e4054000013681708/u@d (1688878916438065152), 7452/78a0ec27b091da5e4054000013681708/u@d (1688878916448550912)]} 0 30682 > solr-mailcow_1 | 2021-01-14 16:09:40.277 INFO (qtp524223214-1325) [ x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts] webapp=/solr path=/update params={}{add=[7463/78a0ec27b091da5e4054000013681708/u@d (1688879057103486976)]} 0 1 > solr-mailcow_1 | 2021-01-14 16:10:00.628 INFO (qtp524223214-1009) [ x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts] webapp=/solr path=/update params={}{add=[7453/78a0ec27b091da5e4054000013681708/u@d (1688878916486299648), 7454/78a0ec27b091da5e4054000013681708/u@d (1688878916489445376), 7455/78a0ec27b091da5e4054000013681708/u@d (1688878916496785408), 7456/78a0ec27b091da5e4054000013681708/u@d (1688878917584158720), 7457/78a0ec27b091da5e4054000013681708/u@d (1688878994974310400), 7458/78a0ec27b091da5e4054000013681708/u@d (1688879073177108480), 7459/78a0ec27b091da5e4054000013681708/u@d (1688879074234073088), 7460/78a0ec27b091da5e4054000013681708/u@d (1688879075288940544), 7461/78a0ec27b091da5e4054000013681708/u@d (1688879076339613696), 7462/78a0ec27b091da5e4054000013681708/u@d (1688879077392384000)]} 0 154455 This results in the following error on the console where I start reindexing: > $ docker-compose exec dovecot-mailcow doveadm index -u u@d 'Sent' > doveadm(u@d): Error: fts_solr: Indexing failed: Request timed out (Request queued 134.122 secs ago, 1 send attempts in 134.098 secs, 131.923 in http ioloop, 0.000 in other ioloops, connected 376.408 secs ago) > doveadm(u@d): Error: Mailbox Sent: Mail search failed: Internal error occurred. Refer to server log for more information. [2021-01-14 17:09:40] > doveadm(u@d): Error: Mailbox Sent: Transaction commit failed: FTS transaction commit failed: backend deinit The last message about indexed block of ten messages (2021-01-14 16:10:00.628 7453-7462) arrives already after reindexing error on the other console occurs and doveadm exits. Interestingly, exactly at the time mentioned in the error message (2021-01-14 17:09:40, i.e. 16:06:40 - I don’t know why timezone differs) a message about indexing of a single message 7463 arrives (which is actually NEXT message to the block that gets indexed 20 seconds later). The whole mailbox consists of 8530 messages and doveadm/solr can’t finish indexing it at all starting over and over. Can you please help me understanding the reason of this behaviour? P.S. Is there any possibility to determine what message in vmail maildir corresponds to solr log, e.g. to 7463/78a0ec27b091da5e4054000013681708/u@d (1688879057103486976) ? Thanks, Programmierus

2 4

Additional custom fields in map dict with static values.
by Mimiko 17 Jan '21

17 Jan '21

Hello. Dovector version 2.2.27. How can I add custom fields in the map for the last_login. For example: map { pattern = shared/last_login/imap/$user/$client_ip table = users_last_login value_field = last_login_imap_int value_type = string fields { userid = $user last_login_client_ip_imap = $client_ip custom_field_name = some_static_value } }

1 0

Antispam plugin
by Maciej Milaszewski 17 Jan '21

17 Jan '21

Hi System centos8 + dovecot-2.3.8 from repo # 2.3.8 (9df20d2db): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.8 (b7b03ba2) # OS: Linux 4.18.0-193.19.1.el8_2.x86_64 x86_64 CentOS Linux release 8.2.2004 (Core) I need "Antispam plugin". What antispam-plugin I must use ? In older version dovecot-2.2.36.4 i use "dovecot-antispam-plugin" but in centos I had a problem with configure - probably toold wersion "./configure: line 3193: DC_DOVECOT: command not found" In wiki dovect is "antispam-plugin" I try this http://hg.dovecot.org/dovecot-antispam-plugin but get 404 Backand spamassassin

4 3

Re: dovecot 2.3.13 : make check FAILURE : Assert failed: buffer_append_full_file
by steve＠keptprivate.com 16 Jan '21

16 Jan '21

I was experiencing multiple failures with make check on a fresh installation of CentOS 8.3.The solution for me was to use mock instead of rpmbuild. (I was not building as root with rpmbuild.) With mock all tests were successful. Sent from my T-Mobile 4G LTE device------ Original message------From: J LumbyDate: Sat, Jan 16, 2021 11:31 AMTo: dovecot(a)dovecot.org;Cc: Subject:dovecot 2.3.13 : make check FAILURE : Assert failed: buffer_append_full_fileAfter successfully building dovecot 2.3.13 (linux kernel 5.10.1 , glibc-2.32 , gcc-9.3) make check had one failure as follows : test-buffer-istream.c:54: Assert failed: buffer_append_full_file(result, TEST_FILENAME, SIZE_MAX, &error) == BUFFER_APPEND_READ_ERROR test-buffer-istream.c:56: Assert failed: error != NULL && *error != '\0' buffer_append_full_file .............................................. : FAILED After a brief look at the referenced code in test-buffer-istream.c , I can't find out what this FAIL really means or whether it is serious. The assert is finding that the result of the call to buffer_append_full_file is not BUFFER_APPEND_READ_ERROR, but it does not report what the result code actually was. Maybe errno was actually 0 and call succeeded? I don't know. Nor can I see how to add some code to find out. Can anyone offer any advice on what this means and/or how to investigate? Cheers, John Lumby

1 0

outlook 2019 imap folder subscription
by Alexander Rivanykov 16 Jan '21

16 Jan '21

1 0

The use of %w in password_query leads to "Failed to expand plugin setting" error
by Filidor Wiese 16 Jan '21

16 Jan '21

Hi, I'm trying to convert my existing users to a more modern password scheme by following the how-to at https://wiki.dovecot.org/HowTo/ConvertPasswordSchemes. One of the steps is to include the use of '%w' in the password_query, like so: password_query = \ SELECT domain, password, '%w' AS userdb_plain_pass, \ domain as userdb_domain, concat('*:storage=', quota) AS userdb_quota_rule, 5000 as userdb_uid, 5000 as userdb_gid, '/home/%d/%n' as userdb_home \ FROM users WHERE (catch='%n' AND domain='%d') and also to configure: userdb { driver = prefetch } in order to combine the user/password_query into one. Now that all seemed to work well, except for one thing. When a user has a % sign in their password, the following error occurs: Error: Failed to expand plugin setting plain_pass = 'Tfew3322gYEp$%5Qjk0': Unknown variable '%Q' Which indicates that dovecot is trying to expand variables in the password. As a consequence, the login process fails. Is there some way around this behavior? Thanks in advance, Filidor Wiese

4 5

Replication issue: cannot delete or rename folders
by ppq＠tuta.io 15 Jan '21

15 Jan '21

Hi all, I'm trying to replace a shared NFS (rock solid, btw) with a replicated two-node setup. However I've been struggling with an issue connected in some way with the replication between the two servers (master-master). The issue is once a folder (say "aaa") is created one one account, it cannot be renamed or deleted. If deleted, it will instantly reappear (when replication is running) or when renamed to "bbb", the operation will fail with an error like the one below: Jan 15 18:21:22 ms1 dovecot: dsync-local(test2(a)mydomain.ext)<JtJJARLPAWBPJAAAxdOQ8Q>: Error: rename(/var/vmail-local/mydomain.ext/test2/idx/.bbb <http://mydomain.ext/test2/idx/.bbb>, /var/vmail-local/mydomain.ext/test2/idx/.aaa <http://mydomain.ext/test2/idx/.aaa>) failed: Directory not empty Jan 15 18:21:22 ms1 dovecot: dsync-local(test2(a)mydomain.ext)<JtJJARLPAWBPJAAAxdOQ8Q>: Error: rename(/var/vmail-local/mydomain.ext/test2/idx/.bbb <http://mydomain.ext/test2/idx/.bbb>, /var/vmail-local/mydomain.ext/test2/idx/.aaa <http://mydomain.ext/test2/idx/.aaa>) failed: Directory not empty I can see that the index directory contains both the .aaa and .bbb index directories with dovecot.log files inside. If I stop the one of the nodes all works nicely and I can create, delete and rename folders at will. My setup is as below. dovecot --version -> 2.3.4.1 (f79e8e7e4) the indexes are in a separate directory on /var/vmail-local/ (performance reasons). the mail spool is mounted on /var/vmail/ One node has local disks for everything. It runs with mmap_disable=no, mail_fsync=optimized, mail_nfs_storage=no, mail_nfs_index=no The other node has an NFS based /var/vmail/ and local disks for indexes. On this node I'm using the following settings: mmap_disable=yes, mail_fsync=always, mail_nfs_storage=yes, mail_nfs_index=no The nfs server is v4 The two servers are "orchestrated" by a two-node director cluster. I'm sure I'm missing or misconfigured something. The doveconf -n config is, part from the NFS quick, the same on both nodes as follows: -------- # 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.4 () doveconf: Warning: service auth { client_limit=1000 } is lower than required under max. load (2012) doveconf: Warning: service anvil { client_limit=1000 } is lower than required under max. load (1515) # OS: Linux 5.4.78-2-pve x86_64 Debian 10.7 # Hostname: dovecot1.mydomain.ext auth_master_user_separator = + auth_mechanisms = plain login default_process_limit = 500 disable_plaintext_auth = no doveadm_password = # hidden, use -P to show it doveadm_port = 12727 imap_capability = +SPECIAL-USE XLIST listen = *,[::] lmtp_rcpt_check_quota = yes log_timestamp = "%Y-%m-%d %H:%M:%S " login_trusted_networks = 172.16.20.0/24 172.16.30.0/24 mail_fsync = always mail_max_userip_connections = 100 mail_nfs_storage = yes mail_plugins = quota notify replication lazy_expunge acl mail_privileged_group = vmail mmap_disable = yes namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox EXPUNGED { autoexpunge = 1 days autoexpunge_max_mails = 20 } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = separator = . } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } passdb { args = /etc/dovecot/master-users driver = passwd-file master = yes result_success = continue } passdb { driver = pam } plugin { acl = vfile:/etc/dovecot/dovecot.acl lazy_expunge = EXPUNGED mail_replica = tcp:172.16.30.100:12727 quota = dict:user::file:/var/vmail/%d/%n/.quotausage quota_rule = EXPUNGED:ignore quota_status_nouser = DUNNO quota_status_overquota = 552 5.2.2 Mailbox is full quota_status_success = DUNNO sieve = /var/vmail/%d/%n/.sieve sieve_after = /var/vmail/%d/%n/.ispconfig.sieve sieve_before = /var/vmail/%d/%n/.ispconfig-before.sieve sieve_max_actions = 100 sieve_max_redirects = 25 sieve_max_script_size = 2M } protocols = imap pop3 lmtp service aggregator { fifo_listener replication-notify-fifo { group = root mode = 0660 user = vmail } unix_listener replication-notify { group = root mode = 0660 user = vmail } } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } unix_listener auth-userdb { group = vmail mode = 0600 user = vmail } user = root } service doveadm { inet_listener { port = 12727 } } service imap-login { client_limit = 1000 process_limit = 512 } service lmtp { inet_listener lmtp { port = 24 } unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service quota-status { client_limit = 1 executable = quota-status -p postfix unix_listener /var/spool/postfix/private/quota-status { group = postfix mode = 0660 user = postfix } } service replicator { process_min_avail = 1 unix_listener replicator-doveadm { mode = 0600 user = vmail } } service stats { unix_listener stats-reader { group = vmail mode = 0660 user = vmail } unix_listener stats-writer { group = vmail mode = 0660 user = vmail } } ssl = required ssl_cert = </etc/letsencrypt/live/mail.mydomain.ext/fullchain.pem <http://mail.mydomain.ext/fullchain.pem> ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } userdb { driver = passwd } protocol imap { auth_verbose = yes mail_plugins = quota imap_quota notify replication lazy_expunge acl } protocol pop3 { auth_verbose = yes mail_plugins = quota notify replication lazy_expunge acl pop3_uidl_format = %08Xu%08Xv } protocol lda { mail_plugins = sieve quota notify replication lazy_expunge acl postmaster_address = postmaster(a)dovecot1.mydomain.ext } protocol lmtp { mail_plugins = quota sieve notify replication lazy_expunge acl postmaster_address = postmaster(a)dovecot1.mydomain.ext } -------------- My sql config is this: --- password_query = SELECT email as user, password, maildir as userdb_home, CONCAT( maildir_format, ':', maildir, '/', IF(maildir_format='maildir','Maildir',maildir_format)) as userdb_mail, uid as userdb_uid, gid as userdb_gid, CONCAT('*:storage=', quota, 'B') AS userdb_quota_rule, CONCAT(maildir, '/.sieve') as userdb_sieve FROM mail_user WHERE (login = '%u' OR email = '%u') AND `disable%Ls` = 'n' AND server_id = '20' AND EXISTS (SELECT domain_id FROM mail_domain WHERE domain = '%d' AND active = 'y' AND server_id = 20) user_query = SELECT email as user, maildir as home, CONCAT( maildir_format, ':', maildir, '/', IF(maildir_format='maildir','Maildir',maildir_format),':INDEX=/var/vmail-local/%d/%n/idx') as mail, uid, gid, CONCAT('*:storage=', quota, 'B') AS quota_rule, CONCAT(maildir, '/.sieve') as sieve FROM mail_user WHERE (login = '%u' OR email = '%u') AND `disable%Ls` = 'n' AND server_id = '20' --- Best regards,Dave

1 0

doveadm, userdb, and ssl=any-cert
by Felipe Gasper 15 Jan '21

15 Jan '21

Hello, We have a server that answers userdb queries for Dovecot. As of 2.3.11 we’re finding that if proxying fields like `ssl=any-cert` are in a userdb response for doveadm, then doveadm complains about not recognizing that field, e.g.: ----- doveadm(_mainaccount(a)xferme.tld): Error: User lookup failed: Invalid settings in userdb: Invalid userdb input 'ssl=any-cert': Invalid value: any-cert doveadm(_mainaccount(a)xferme.tld): Warning: Event 0x55a3f911b9c0 leaked (parent=(nil)): mail-storage-service.c:1335 ----- We can avoid sending this field in response when doveadm is the requesting service, but was this apparent change in 2.3.11 intended? Thank you! cheers, -Felipe Gasper

1 0

Authentication segfault with Dovecot 2.3.13
by Harald Leithner 14 Jan '21

14 Jan '21

Hi, we have a problem upgrading Dovecot from 2.2 to 2.3.13 on one server it seems one user triggers a segfault while trying to authenticate. The user works fine with 2.2.36.4, our last update try mid-late 2020 was aborted because of this reason. While debugging the problem we noticed that the "auth_debug_passwords = no" option doesn't work at least in our logfiles are the passwords logged. We replaced the password in the log with "THIS_SHOULD_NOT_GET_LOGGED" and the user part with "user@redacted". The user uses APOP for authentication, but other users login successfully with APOP. Here is a stacktrace and a log dump: Jan 6 16:29:44 mail kernel: auth[2208397]: segfault at ec ip 00007f67fc147174 sp 00007ffeed993150 error 4 in libdovecot.so.0.0.0[7f67fc06e000+fc000] Jan 6 16:29:44 mail kernel: Code: 1f 80 00 00 00 00 41 54 e8 79 fd ff ff 31 f6 49 89 c4 48 89 c7 31 c0 e8 ca f8 ff ff 4c 89 e0 41 5c c3 0f 1f 40 00 53 48 89 fb <f6> 87 ec 00 00 00 04 75 43 48 83 3d 7b aa 0a 00 00 0f 85 50 15 f4 Jan 6 16:29:44 mail systemd[1]: Started Process Core Dump (PID 2208677/UID 0). Jan 6 16:29:44 mail systemd-coredump[2208678]: Process 2208397 (auth) of user 489 dumped core.#012#012Stack trace of thread 2208397:#012#0 0x00007f67fc147174 event_create_passthrough (libdovecot.so.0 + 0x116174)#012#1 0x0000555678812d6e auth_request_finished_event (auth + 0x1bd6e)#012#2 0x00005556788159ae auth_request_log_finished (auth + 0x1e9ae)#012#3 0x0000555678816ee0 n/a (auth + 0x1fee0)#012#4 0x0000555678826dc1 passdb_handle_credentials (auth + 0x2fdc1)#012#5 0x0000555678816c7e n/a (auth + 0x1fc7e)#012#6 0x0000555678824f27 n/a (auth + 0x2df27)#012#7 0x000055567881b02d auth_request_handler_auth_begin (auth + 0x2402d)#012#8 0x000055567880dfaf n/a (auth + 0x16faf)#012#9 0x00007f67fc143a79 io_loop_call_io (libdovecot.so.0 + 0x112a79)#012#10 0x00007f67fc144ae2 io_loop_handler_run_internal (libdovecot.so.0 + 0x113ae2)#012#11 0x00007f67fc143b21 io_loop_handler_run (libdovecot.so.0 + 0x112b21)#012#12 0x00007f67fc143ce0 io_loop_run (libdovecot.so.0 + 0x112ce0)#012#13 0x00007f67fc0b96f3 master_service_run (libdovecot.so.0 + 0x886f3)#012#14 0x000055567880c2db main (auth + 0x152db)#012#15 0x00007f67fbc9d042 __libc_start_main (libc.so.6 + 0x27042)#012#16 0x000055567880c48e _start (auth + 0x1548e) Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: AUTH#011134#011PLAIN#011service=imap#011session=tgog/jy4erm5j7ZO#011lip=lan-ip#011rip=client-ip#011lport=143#011rport=47482 Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client passdb out: CONT#011134 Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: CONT<hidden> Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): cache expired Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: Handling PASSV request Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): query: SELECT passwd as password, '127.0.0.1' as host, userid as destuser, passwd AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM dbmail_users WHERE userid='user@redacted' UNION (SELECT password as password, '127.0.0.1' as host, username as destuser, password AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM sasl_fake_auth WHERE username='user@redacted') limit 1; Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Password mismatch Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: Finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<tgog/jy4erm5j7ZO>): Auth request finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: AUTH#011443#011APOP#011service=pop3#011secured=tls#011session=n58h/jy4a0i5j7ZO#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=18539#011local_name=mail#011resp=<hidden> Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<n58h/jy4a0i5j7ZO>): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<n58h/jy4a0i5j7ZO>): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<n58h/jy4a0i5j7ZO>): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<n58h/jy4a0i5j7ZO>): Auth request finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011443#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=<user@redacted>, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:29:44 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208397 killed with signal 11 (core dumped)h-worker<1>: Handling PASSV request Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: AUTH#01179#011PLAIN#011service=imap#011session=QY6V2zy4FUm5j7YD#011lip=lan-ip#011rip=client-ip#011lport=143#011rport=18709 Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client passdb out: CONT#01179 Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: CONT<hidden> Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): cache expired Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: Handling PASSV request Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): query: SELECT passwd as password, '127.0.0.1' as host, userid as destuser, passwd AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM dbmail_users WHERE userid='user@redacted' UNION (SELECT password as password, '127.0.0.1' as host, username as destuser, password AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM sasl_fake_auth WHERE username='user@redacted') limit 1; Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Password mismatch Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: Finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Auth request finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: AUTH#011215#011APOP#011service=pop3#011secured=tls#011session=ZJWX2zy4VzO5j7YD#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=13143#011local_name=mail#011resp=<hidden> Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Auth request finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011215#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=<user@redacted>, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:20:05 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208074 killed with signal 11 (core dumped) Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: client in: AUTH#011218#011APOP#011service=pop3#011secured=tls#011session=wXyB3Dy4W0i5j7YD#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=18523#011local_name=mail#011resp=<hidden> Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Performing passdb lookup Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Finished passdb lookup Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Auth request finished Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011218#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=<user@redacted>, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:20:20 mail dovecot[2208071]: auth-worker(2208392): Debug: conn unix:auth-worker (pid=2208385,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:20:20 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208385 killed with signal 11 (core dumped) Any help is appreciated thanks Harald -- ITronic Harald Leithner Wiedner Hauptstraße 120/5.1, 1050 Wien, Austria Tel: +43-1-545 0 604 Mobil: +43-699-123 78 4 78 Mail: leithner(a)itronic.at | itronic.at

4 10

Dovecot v2.3.13 released
by Aki Tuomi 13 Jan '21

13 Jan '21

We are pleased to release v2.3.13. Please find it from locations below: https://dovecot.org/releases/2.3/dovecot-2.3.13.tar.gz https://dovecot.org/releases/2.3/dovecot-2.3.13.tar.gz.sig Binary packages in https://repo.dovecot.org/ Docker images in https://hub.docker.com/r/dovecot/dovecot Aki Tuomi Open-Xchange oy --- * CVE-2020-24386: Specially crafted command can cause IMAP hibernate to allow logged in user to access other people's emails and filesystem information. * Metric filter and global event filter variable syntax changed to a SQL-like format. See https://doc.dovecot.org/configuration_manual/event_filter/ * auth: Added new aliases for %{variables}. Usage of the old ones is possible, but discouraged. * auth: Removed RPA auth mechanism, SKEY auth mechanism, NTLM auth mechanism and related password schemes. * auth: Removed passdb-sia, passdb-vpopmail and userdb-vpopmail. * auth: Removed postfix postmap socket + auth: Added new fields for auth server events. These fields are now also available for all auth events. See https://doc.dovecot.org/admin_manual/list_of_events/#authentication-server for details. + imap-hibernate: Added imap_client_hibernated, imap_client_unhibernated and imap_client_unhibernate_retried events. See https://doc.dovecot.org/admin_manual/list_of_events/ for details. + lib-index: Added new mail_index_recreated event. See https://doc.dovecot.org/admin_manual/list_of_events/#mail-index-recreated + lib-sql: Support TLS options for cassandra driver. This requires cpp-driver v2.15 (or later) to work reliably. + lib-storage: Missing $HasAttachment / $HasNoAttachment flags are now added to existing mails if mail_attachment_detection_option=add-flags and it can be done inexpensively. + login proxy: Added login_proxy_max_reconnects setting (default 3) to control how many reconnections are attempted. + login proxy: imap/pop3/submission/managesieve proxying now supports reconnection retrying on more than just connect() failure. Any error except a non-temporary authentication failure will result in reconnect attempts. - auth: Lua passdb/userdb leaks stack elements per call, eventually causing the stack to become too deep and crashing the auth or auth-worker process. - auth: SASL authentication PLAIN mechanism could be used to trigger read buffer overflow. However, this doesn't seem to be exploitable in any way. - auth: v2.3.11 regression: GSSAPI authentication fails because dovecot disallows NUL bytes for it. - dict: Process used too much CPU when iterating keys, because each key used a separate write() syscall. - doveadm-server: Crash could occur if logging was done outside command handling. For example http-client could have done debug logging afterwards, resulting in either segfault or Panic: file http-client.c: line 642 (http_client_context_close): assertion failed: (cctx->clients_list == NULL). - doveadm-server: v2.3.11 regression: Trying to connect to doveadm server process via starttls assert-crashed if there were no ssl=yes listeners: Panic: file master-service-ssl.c: line 22 (master_service_ssl_init): assertion failed: (service->ssl_ctx_initialized). - fts-solr: HTTP requests may have assert-crashed: Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) - imap: IMAP NOTIFY could crash with a segmentation fault due to a bad configuration that causes errors. Sending the error responses to the client can cause the segmentation fault. This can for example happen when several namespaces use the same mail storage location. - imap: IMAP NOTIFY used on a shared namespace that doesn't actually exist (e.g. public namespace for a nonexistent user) can crash with a panic: Panic: Leaked view for index /tmp/home/asdf/mdbox/dovecot.list.index: Opened in (null):0 - imap: IMAP session can crash with QRESYNC extension if many changes are done before asking for expunged mails since last sync. - imap: Process might hang indefinitely if client disconnects after sending some long-running commands pipelined, for example FETCH+LOGOUT. - lib-compress: Mitigate crashes when configuring a not compiled in compression. Errors with compression configuration now distinguish between not supported and unknown. - lib-compression: Using xz/lzma compression in v2.3.11 could have written truncated output in some situations. This would result in "Broken pipe" read errors when trying to read it back. - lib-compression: zstd compression could have crashed in some situations: Panic: file ostream.c: line 287 (o_stream_sendv_int): assertion failed: (!stream->blocking) - lib-dict: dict client could have crashed in some rare situations when iterating keys. - lib-http: Fix several assert-crashes in HTTP client. - lib-index: v2.3.11 regression: When mails were expunged at the same time as lots of new content was being saved to the cache (e.g. cache file was lost and is being re-filled) a deadlock could occur with dovecot.index.cache / dovecot.index.log. - lib-index: v2.3.11 regression: dovecot.index.cache file was being purged (rewritten) too often when it had a field that hadn't been accessed for over 1 month, but less than 2 months. Every cache file change caused a purging in this situation. - lib-mail: MIME parts were not returned correctly by Dovecot MIME parser. Regression caused by fixing CVE-2020-12100. - lib-mail: When max nested MIME parts were reached, IMAP BODYSTRUCTURE was written in a way that may have caused confusion for both IMAP clients and Dovecot itself when parsing it. The truncated part is now written out using application/octet-stream MIME type. - lib-mail: v2.3.11 regression: Mail delivery / parsing crashed when the 10000th MIME part was message/rfc822 (or if parent was multipart/digest): Panic: file message-parser.c: line 167 (message_part_append): assertion failed: (ctx->total_parts_count <= ctx->max_total_mime_parts). - lib-oauth2: Dovecot incorrectly required oauth2 server introspection reply to contain username with invalid token. - lib-ssl-iostream, lib-dcrypt: Fix building with OpenSSL that has deprecated APIs disabled. - lib-storage: When mail's size is different from the cached one (in dovecot.index.cache or Maildir S=size in the filename), this is handled by logging "Cached message size smaller/larger than expected" error. However, in some situations this also ended up crashing with: Panic: file istream.c: line 315 (i_stream_read_memarea): assertion failed: (old_size <= _stream->pos - _stream->skip). - lib-storage: v2.3 regression: Copying/moving mails was taking much more memory than before. This was mainly visible when copying/moving thousands of mails in a single transaction. - lib-storage: v2.3.11 regression: Searching messages assert-crashed (without FTS): Panic: file message-parser.c: line 174 (message_part_finish): assertion failed: (ctx->nested_parts_count > 0). - lib: Dovecot v2.3 moved signal handlers around in ioloops, causing more CPU usage than in v2.2. - lib: Fixed JSON parsing: '\' escape sequence may have wrongly resulted in error if it happened to be at read boundary. Any NUL characters and '\u0000' will now result in parsing error instead of silently truncating the data. - lmtp, submission: Server may hang if SSL client connection disconnects during the delivery. If this happened repeated, it could have ended up reaching process_limit and preventing any further lmtp/submission deliveries. - lmtp: Proxy does not always properly log TLS connection problems as errors; in some cases, only a debug message is logged if enabled. - lmtp: The LMTP service can hang when commands are pipelined. This can particularly occur when one command in the middle of the pipeline fails. One example of this occurs for proxied LMTP transactions in which the final DATA or BDAT command is pipelined after a failing RCPT command. - login-proxy: The login_source_ips setting has no effect, and therefore the proxy source IPs are not cycled through as they should be. - master: Process was using 100% CPU in some situations when a broken service was being throttled. - pop3-login: POP3 login would fail with "Input buffer full" if the initial response for SASL was too long. - stats: Crash would occur when generating openmetrics data for metrics using aggregating functions.

5 6