- dovecot - dovecot.org

blocking - sql(acastus@example.ch,IP): unknown user
by mauric＠gmx.ch 19 May '21

19 May '21

hello running with following Setup booster, postfix, Dovecot, mysql and meny other nice tools searching for solutions I see meny other running with same questions like this, so please what i need to read or setup that i don't receive so many failed logon try? "unknown user" i see, meny "fix" this fail2ban, but iam shure that Dovecot has also any solution for this? so friendly asking how to close this request from trying for failed logon. May 14 time Dovecot/auth-worker(8075): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth May 14 time Dovecot/auth-worker(8075): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so May 14 time Dovecot/auth-worker(8075): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so May 14 time Dovecot/auth-worker(8043): Debug: sql(acastus(a)example.ch,IP): query: SELECT username AS user, password, '/folder/example.ch/acastus' AS userdb_home, '10000' AS userdb_uid, '10000' AS userdb_gid, CONCAT('maildir:storage=', (quota*1024)) as userdb_quota FROM mailbox WHERE username='acastus(a)example.ch' AND active = 1 May 14 time Dovecot/auth-worker(8026): Info: sql(acastus(a)example.ch,IP): unknown user thanks Mauri

3 2

Separating Dovecot and Postfix
by White, Daniel E. (GSFC-770.0)[NICS] 14 May '21

14 May '21

I am struggling to update a very old set of mail servers. Some are supposed to be relays (MTAs by my understanding) while others are where the mailboxes live (MDA) In rebuilding the MDA servers, is postfix required on the same server or can dovecot connect to postfix on a separate MTA server ? The old MDAs have both installed, but the config files are a mess.

3 4

lmtp(5672): Fatal: master: service(lmtp): child 5672 killed with signal 11 (core dumped)
by Alex 14 May '21

14 May '21

Hi Sometimes I see such lines in the logs May 10 23:15:31 mail dovecot[374]: lmtp(452): Fatal: master: service(lmtp): child 452 killed with signal 11 (core not dumped - https://dovecot.org/bugreport.html#coredumps - set /proc/sys/fs/suid_dumpable to 2) May 12 18:50:19 mail dovecot[374]: lmtp(3533): Fatal: master: service(lmtp): child 3533 killed with signal 11 (core not dumped - https://dovecot.org/bugreport.html#coredumps - set /proc/sys/fs/suid_dumpable to 2) May 13 17:21:34 mail dovecot[4910]: lmtp(5672): Fatal: master: service(lmtp): child 5672 killed with signal 11 (core dumped) and postfix logs: postfix/lmtp[28025]: 502DA17E1BC3: to=<email(a)domain.com>, relay=1.0.1.1[1.0.1.1]:11111, delay=0.78, delays=0.69/0/0.09/0, dsn=4.4.2, status=deferred (lost connection with 1.0.1.1[1.0.1.1] while receiving the initial server greeting) It was the spam message This error was in some previous versions too Information for debugging: dovecot is working in lxc container with Centos 8 in Proxmox 5.4.101-1-pve #1 SMP PVE 5.4.101-1 (Fri, 26 Feb 2021 13:13:09 +0100) x86_64 x86_64 x86_64 GNU/Linux # gdb /usr/libexec/dovecot/lmtp 'core-lmtp-5672-!usr!libexec!dovecot!lmtp' GNU gdb (GDB) Red Hat Enterprise Linux 8.2-12.el8 Copyright (C) 2018 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-redhat-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/libexec/dovecot/lmtp...Reading symbols from /usr/lib/debug/usr/libexec/dovecot/lmtp-2.3.14-1.0.rhel8.x86_64.debug...done. done. [New LWP 5672] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". Core was generated by `dovecot/lmtp'. Program terminated with signal SIGSEGV, Segmentation fault. #0 __strlen_sse2 () at ../sysdeps/x86_64/multiarch/../strlen.S:120 120 movdqu (%rax), %xmm4 (gdb) bt #0 __strlen_sse2 () at ../sysdeps/x86_64/multiarch/../strlen.S:120 #1 0x00007fbc3f65725b in p_strdup (pool=0x5620ae47d3e0, str=0x8 <error: Cannot access memory at address 0x8>) at strfuncs.c:51 #2 0x00007fbc3f5b292a in setting_copy () at settings-parser.c:1538 #3 0x00007fbc3f5b2d8a in settings_dup_full () at settings-parser.c:1600 #4 0x00007fbc3f9547ba in mail_user_alloc (parent_event=0x0, username=0x7fbc3fa0b24a "raw mail user", set_info=0x5620ae46e458, set=0x5620ae430220) at mail-user.c:113 #5 0x00007fbc3f9a1dc5 in raw_storage_create_from_set (set_info=<optimized out>, set=<optimized out>) at raw-storage.c:25 #6 0x00005620ad66769a in client_raw_user_create (client=0x5620ae4aa8b8, client=0x5620ae4aa8b8) at lmtp-client.c:105 #7 client_create (fd_in=17, fd_out=17, conn=0x7fff7071af50) at lmtp-client.c:177 #8 0x00007fbc3f5acc99 in master_service_client_connection_callback (service=0x5620ae427130, conn=0x7fff7071af50) at master-service.c:980 #9 0x00007fbc3f5ad015 in master_service_listen (l=0x5620ae427610) at master-service.c:1212 #10 0x00007fbc3f63904d in io_loop_call_io (io=0x5620ae5032b0) at ioloop.c:714 #11 0x00007fbc3f63a679 in io_loop_handler_run_internal (ioloop=ioloop@entry=0x5620ae4272d0) at ioloop-epoll.c:222 #12 0x00007fbc3f6390f0 in io_loop_handler_run (ioloop=0x5620ae4272d0) at ioloop.c:766 #13 0x00007fbc3f639268 in io_loop_run (ioloop=0x5620ae4272d0) at ioloop.c:739 #14 0x00007fbc3f5ac557 in master_service_run (service=0x5620ae427130, callback=callback@entry=0x5620ad666fa0 <client_connected>) at master-service.c:853 #15 0x00005620ad666dcd in main (argc=<optimized out>, argv=<optimized out>) at main.c:168 (gdb) bt full #0 __strlen_sse2 () at ../sysdeps/x86_64/multiarch/../strlen.S:120 No locals. #1 0x00007fbc3f65725b in p_strdup (pool=0x5620ae47d3e0, str=0x8 <error: Cannot access memory at address 0x8>) at strfuncs.c:51 mem = <optimized out> len = <optimized out> #2 0x00007fbc3f5b292a in setting_copy () at settings-parser.c:1538 strlist_info = {module_name = 0x0, defines = 0x0, defaults = 0x0, type_offset = 18446744073709551615, struct_size = 0, parent_offset = 18446744073709551615, parent = 0x0, check_func = 0x0, expand_check_func = 0x0, dependencies = 0x0, dynamic_parsers = 0x0} #3 0x00007fbc3f5b2d8a in settings_dup_full () at settings-parser.c:1600 strlist_info = {module_name = 0x0, defines = 0x0, defaults = 0x0, type_offset = 18446744073709551615, struct_size = 0, parent_offset = 18446744073709551615, parent = 0x0, check_func = 0x0, expand_check_func = 0x0, dependencies = 0x0, dynamic_parsers = 0x0} #4 0x00007fbc3f9547ba in mail_user_alloc (parent_event=0x0, username=0x7fbc3fa0b24a "raw mail user", set_info=0x5620ae46e458, set=0x5620ae430220) at mail-user.c:113 pool = 0x5620ae47d3e0 #5 0x00007fbc3f9a1dc5 in raw_storage_create_from_set (set_info=<optimized out>, set=<optimized out>) at raw-storage.c:25 user = <optimized out> ns = <optimized out> ns_set = <optimized out> mail_set = <optimized out> error = 0x7fff7071af50 "\021" #6 0x00005620ad66769a in client_raw_user_create (client=0x5620ae4aa8b8, client=0x5620ae4aa8b8) at lmtp-client.c:105 sets = <optimized out> sets = <optimized out> #7 client_create (fd_in=17, fd_out=17, conn=0x7fff7071af50) at lmtp-client.c:177 rcpt_param_extensions = {0x5620ad66be6b "XRCPTFORWARD", 0x0} cap_rcpt_forward = {name = 0x5620ad66be6b "XRCPTFORWARD", params = 0x0} workarounds = <optimized out> lmtp_set = {protocol = SMTP_PROTOCOL_SMTP, capabilities = SMTP_CAPABILITY_NONE, workarounds = (unknown: 1886498356), hostname = 0x5620ae426760 "", login_greeting = 0x1 <error: Cannot access memory at address 0x1>, rawlog_dir = 0x0, ssl = 0x0, max_client_idle_time_msecs = 1886498432, max_pipelined_commands = 32767, max_bad_commands = 1062726285, max_recipients = 32700, command_limits = {max_parameters_size = 94698362529624, max_auth_size = 140446494082554, max_data_size = 140735079886496}, max_message_size = 94698362822992, mail_param_extensions = 0x2ae426758, rcpt_param_extensions = 0x7fff7071ae34, xclient_extensions = 0x7071aec0, socket_send_buffer_size = 15936827190723348992, socket_recv_buffer_size = 11513522008, event_parent = 0x5620ae46e150, debug = false, auth_optional = false, tls_required = false, mail_path_allow_broken = false, rcpt_domain_optional = false} client = 0x5620ae4aa8b8 pool = <optimized out> #8 0x00007fbc3f5acc99 in master_service_client_connection_callback (service=0x5620ae427130, conn=0x7fff7071af50) at master-service.c:980 No locals. #9 0x00007fbc3f5ad015 in master_service_listen (l=0x5620ae427610) at master-service.c:1212 service = 0x5620ae427130 conn = {fd = 17, listen_fd = 10, name = 0x5620ae4276c0 "lmtp", remote_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\n\000\003e", '\000' <repeats 11 times>, __u6_addr16 = {10, 25859, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {1694695434, 0, 0, 0}}}, ip4 = {s_addr = 1694695434}}}, local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\n\000\n\a", '\000' <repeats 11 times>, __u6_addr16 = {10, 1802, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {118095882, 0, 0, 0}}}, ip4 = {s_addr = 118095882}}}, remote_port = 50660, local_port = 24, real_remote_ip = {family = 2, u = { ip6 = {__in6_u = {__u6_addr8 = "\n\000\003e", '\000' <repeats 11 times>, __u6_addr16 = {10, 25859, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {1694695434, 0, 0, 0}}}, ip4 = {s_addr = 1694695434}}}, real_local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\n\000\n\a", '\000' <repeats 11 times>, __u6_addr16 = {10, 1802, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {118095882, 0, 0, 0}}}, ip4 = { s_addr = 118095882}}}, real_remote_port = 50660, real_local_port = 24, proxy = {hostname = 0x0, cert_common_name = 0x0, alpn = 0x0, alpn_size = 0, ssl = false, ssl_client_cert = false}, proxied = false, fifo = false, ssl = false, accepted = true} #10 0x00007fbc3f63904d in io_loop_call_io (io=0x5620ae5032b0) at ioloop.c:714 ioloop = 0x5620ae4272d0 t_id = 2 __func__ = "io_loop_call_io" #11 0x00007fbc3f63a679 in io_loop_handler_run_internal (ioloop=ioloop@entry=0x5620ae4272d0) at ioloop-epoll.c:222 ctx = 0x5620ae42c5f0 events = <optimized out> event = 0x5620ae42c670 --Type <RET> for more, q to quit, c to continue without paging--c list = 0x5620ae43adc0 io = <optimized out> tv = {tv_sec = 2147483, tv_usec = 0} events_count = <optimized out> msecs = <optimized out> ret = <optimized out> i = 0 j = <optimized out> call = <optimized out> __func__ = "io_loop_handler_run_internal" #12 0x00007fbc3f6390f0 in io_loop_handler_run (ioloop=0x5620ae4272d0) at ioloop.c:766 __func__ = "io_loop_handler_run" #13 0x00007fbc3f639268 in io_loop_run (ioloop=0x5620ae4272d0) at ioloop.c:739 __func__ = "io_loop_run" #14 0x00007fbc3f5ac557 in master_service_run (service=0x5620ae427130, callback=callback@entry=0x5620ad666fa0 <client_connected>) at master-service.c:853 No locals. #15 0x00005620ad666dcd in main (argc=<optimized out>, argv=<optimized out>) at main.c:168 set_roots = {0x5620ad86e640 <smtp_submit_setting_parser_info>, 0x5620ad86e580 <lda_setting_parser_info>, 0x5620ad86e2a0 <lmtp_setting_parser_info>, 0x0} service_flags = <optimized out> storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP | MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP | MAIL_STORAGE_SERVICE_FLAG_NO_LOG_INIT | MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT) tmp_base_dir = 0x5620ae41e758 "" c = <optimized out> error = 0x7fff707492d8 ""

2 2

Outlook creating IMAP folders even though forbidden by ACLs
by Matt Grant 13 May '21

13 May '21

Hi! Is it well known that Outlook cannot process RFC 2086 or RFC 4134 ACLs? We are using Outlook 2013, 2016 and 2019, and with 2013 can definitely create shared folders with content that are not saved to the server, even though Outlook 'pretends' quite erroneously that they are - black hole for critical email that we must keep according to engineering contracts for design documentation purposes. Thank you! Matt Grant

2 1

Problem with replication between two servers (ispconfig)
by Claudio Junior 12 May '21

12 May '21

Hi people, I am setting up replication between two servers. The installation of the servers was done using ispconfig and the operating system is debian 10. The problem is that after following the guide for this configuration, https://wiki.dovecot.org/Replication, when I start the server, replication does not start. I have also checked, via tcpdump, on the port associated with doveadm. If I force it with the command "doveadm -D sync -u user @ domain -d -N -l 30 -U" the replication happens, but it is not updating when the user receives emails on server01. At this time server02 will not receive emails (via postfix), and will also not have users accessing via pop3 or imap, but I have the idea of configuring so that both servers have these services working. The configuration of the servers is below: root@server01:~# doveconf -n # 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.4 () # OS: Linux 4.19.0-16-amd64 x86_64 Debian 10.9 # Hostname: server01.example.net auth_mechanisms = plain login debug_log_path = /var/log/dovecot.debug disable_plaintext_auth = no doveadm_password = # hidden, use -P to show it doveadm_port = 2727 imap_capability = +SEPCIAL-USE XLIST listen = *,[::] lmtp_rcpt_check_quota = yes log_timestamp = "%Y-%m-%d %H:%M:%S " mail_debug = yes mail_max_userip_connections = 100 mail_plugins = quota notify replication mail_privileged_group = vmail namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { auto = subscribe autoexpunge = 60 days special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { auto = subscribe autoexpunge = 60 days special_use = \Trash } prefix = separator = . } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } plugin { mail_replica = tcp:server02.example.net:2727 quota = dict:user::file:/var/vmailquota/%d/%n/.quotausage 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 { mode = 0660 user = vmail } unix_listener replication-notify { 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 = 2727 } unix_listener doveadm-server { user = vmail } } service imap-login { client_limit = 1000 process_limit = 512 } service lmtp { 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 = 0660 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_cert = </etc/postfix/smtpd.cert ssl_cipher_list = ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384 ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it ssl_min_protocol = TLSv1.2 userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } protocol imap { auth_verbose = yes mail_plugins = quota imap_quota } protocol pop3 { auth_verbose = yes mail_plugins = quota pop3_uidl_format = %08Xu%08Xv } protocol lda { mail_plugins = sieve quota postmaster_address = postmaster(a)server01.example.net } protocol lmtp { mail_plugins = quota sieve postmaster_address = postmaster(a)server01.example.net } local_name server01.example.net { ssl_cert = </etc/letsencrypt/live/server01.example.net/fullchain.pem ssl_key = # hidden, use -P to show it } local_name mail.example.net { ssl_cert = </etc/letsencrypt/live/mail.example.net/fullchain.pem ssl_key = # hidden, use -P to show it } local_name mail.otherdomain1.com.br { ssl_cert = </etc/letsencrypt/live/mail.otherdomain1.com.br/fullchain.pem ssl_key = # hidden, use -P to show it } root@server02:/var/vmail# doveconf -n # 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.4 () # OS: Linux 4.19.0-16-amd64 x86_64 Debian 10.9 # Hostname: server02.example.net auth_mechanisms = plain login debug_log_path = /var/log/dovecot.debug disable_plaintext_auth = no doveadm_password = # hidden, use -P to show it doveadm_port = 2727 listen = *,[::] log_timestamp = "%Y-%m-%d %H:%M:%S " mail_debug = yes mail_max_userip_connections = 100 mail_plugins = " notify replication" mail_privileged_group = vmail namespace inbox { inbox = yes location = mailbox Drafts { auto = no special_use = \Drafts } mailbox Junk { auto = subscribe autoexpunge = 60 days special_use = \Junk } mailbox Sent { auto = no special_use = \Sent } mailbox "Sent Messages" { auto = no special_use = \Sent } mailbox Trash { auto = subscribe autoexpunge = 60 days special_use = \Trash } prefix = } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } plugin { mail_replica = tcp:server01.example.net:2727 quota = dict:user::file:/var/vmailquota/%d/%n/.quotausage sieve = /var/vmail/%d/%n/.sieve sieve_max_redirects = 25 } protocols = imap pop3 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 = 2727 } unix_listener doveadm-server { user = vmail } } service imap-login { client_limit = 1000 process_limit = 512 } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service replicator { unix_listener replicator-doveadm { group = root mode = 0660 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_cert = </etc/postfix/smtpd.cert 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 } protocol imap { mail_plugins = quota imap_quota } protocol pop3 { mail_plugins = quota pop3_uidl_format = %08Xu%08Xv } protocol lda { mail_plugins = sieve quota postmaster_address = postmaster(a)example.net } protocol lmtp { mail_plugins = quota sieve postmaster_address = postmaster(a)example.net } root@server02:/var/vmail# Att Claudio Jr. -- Claudio da Silva Junior csjunior(a)gmail.com

2 2

Variable expansion in password field (again?!)
by Mathias Rabe 11 May '21

11 May '21

Hi list, I’m experimenting with the mail-crypt-plugin in Dovecot v2.3.4.1 on Debian 10 Buster. I’m also running a OpenLDAP-Server for user lookup. My LDAP-settings looks like this: hosts = ### dn = cn=###,dc=###,dc=## dnpass = ### tls = yes auth_bind = no ldap_version = 3 base = ou=people,dc=###,dc=## scope = subtree user_attrs = \ =quota_rule=*:bytes=%{ldap:mailQuota}, \ =home=/var/vmail/mailboxes/%d/%{ldap:uid}, \ =mail=maildir:/var/vmail/mailboxes/%d/%{ldap:uid}/mail user_filter = (&(mail=%u)(objectClass=person)(mailEnabled=TRUE)) pass_attrs = mail=user,userPassword=password,=userdb_mail_crypt_private_password=%w,mailCrypt=userdb_mail_crypt_save_version pass_filter = (&(mail=%u)(objectClass=person)(mailEnabled=TRUE)) iterate_attrs = mail=user iterate_filter = (objectClass=person) default_pass_scheme = SSHA-512 The users can log-in and everything works fine including the mail-crypt-plugin until an user password contains a % I get the following error message (example): Error: Failed to expand plugin setting mail_crypt_private_password = '"1234%Passwort"': Unknown variable '%P‘ I’ve found some mails but I didn’t found a solution. It seems that Dovecot tries to expand some variable in the password: https://dovecot.org/pipermail/dovecot/2019-July/116338.html https://dovecot.org/pipermail/dovecot/2020-April/118634.html So this seems to be a bug or something. Is there any new information on this topic or even any solution or workaround? Thank you very much! Mathias

3 2

sudden performance drop - i/o related
by Marcin Gryszkalis 11 May '21

11 May '21

Hi I have exim/dovecot server that worked great for last few years and two weeks ago it got ill ;) First were users reporting errors on saving mails to Sent (timeouts). Now the logs are infested with warnings about long waits: May 10 10:18: Maildir /mail/xxx Synchronization took 193 seconds (1 new msgs, 0 flag change attempts, 0 expunge attempts) May 10 10:18: Maildir /mail/xxx Synchronization took 125 seconds (1 new msgs, 0 flag change attempts, 0 expunge attempts) May 10 10:18: Maildir /mail/xxx Synchronization took 211 seconds (1 new msgs, 0 flag change attempts, 0 expunge attempts) May 10 10:18: Maildir /mail/xxx Synchronization took 107 seconds (8 new msgs, 0 flag change attempts, 0 expunge attempts) May 10 10:18: Transaction log file /mail/xxx was locked for 36 seconds (Mailbox was synchronized) May 10 10:18: Transaction log file /mail/xxx was locked for 160 seconds (Mailbox was synchronized) May 10 10:18: Transaction log file /mail/xxx was locked for 72 seconds (Mailbox was synchronized) May 10 10:18: Locking transaction log file /mail/xxx took 60 seconds (syncing) May 10 10:18: Locking transaction log file /mail/xxx took 38 seconds (syncing) May 10 10:18: Locking transaction log file /mail/xxx took 35 seconds (syncing) It looks like i/o risen from 150writes/s to 500writes/s (in top hours) - but there's no real change in number of emails or the volume. Number of users is steady (~100 active users, ~250 imap sessions), number of emails (by count or by volume) is rising and falling within 15% margin. The box is FreeBSD 11.4, dovecot is 2.3.13. Filesystem is ZFS, disks are fine, free space is around 20% (~200GB) Layout is Maildir. CPU is not overloaded (2x6core), same with memory (48GB). I didn't change anything in configuration. Tonight I did some finetuning like maildir_copy_with_hardlinks=yes or mail_fsync=never/optimized (I'm not happy with that but I'm afraid it won't really help and I'll be able to revert that). I'm also thinking about switching from Maildir to sdbox (I know it won't hurt). I don't know where to look to find where the i/o goes. I don't have any metrics/stats enabled (I looked at the docs but it looks it's not really simple and needs some digging to get valuable config). Maybe somebody has suggestions what to look for? For detailed per-process stats I need to rebuild kernel with dtrace (other night I guess)... Simple top (in i/o mode - similar to linux's iotop) doesn't catch short living processes (like LDA deliveries). best regards -- Marcin Gryszkalis, PGP 0xA5DBEEC7 http://fork.pl/gpg.txt

2 3

mdbox / selecting folder accesses hundrets of others
by Florian Lohoff 10 May '21

10 May '21

Dovecot: 2.3.4 Hi, i am debugging a problem where after a force-resync removed all cache files (All files are 44 byte). Trying to open a folder takes literally minutes (Huge mailbox - 220K folder, 45GByte compressed storage) After i straced the imap process i can see the imap process accesses hundrets of other completely unrelated folders: Thats from the logfile - You can see mutt selecting the mailbox "zzzzzzt": May 07 18:05:19 imap(inbox@wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: fts: No fts setting - plugin disabled May 07 18:05:19 imap(inbox@wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping May 07 18:05:19 imap(inbox@wasteland)<20381><hlkrmL/B5qwgAwDvnxMdAGcc/5MSpYxQ>: Debug: Mailbox zzzzzzt: Mailbox opened because: SELECT From strace -p 20381 - This goes on for minutes opening thousands of unrelated folders. It is noteworthy that it mostly opens nested folders which are rare here: [...] open("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15 fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 getdents(15, /* 3 entries */, 32768) = 72 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt/yeah", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/gerries/are/hawt/yeah/dbox-Mails", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 getdents(15, /* 0 entries */, 32768) = 0 close(15) = 0 open("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15 fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 getdents(15, /* 3 entries */, 32768) = 80 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594/b3914", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/karl588594/b3914/dbox-Mails", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 getdents(15, /* 0 entries */, 32768) = 0 close(15) = 0 open("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 15 fstat(15, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 getdents(15, /* 4 entries */, 32768) = 104 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben/gang", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 stat("/var/vmail/wasteland/inbox/mdbox/mailboxes/ben/gang/dbox-Mails", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0 Reopening the same folder again is quick and seamless. So it seems this is some cache recreation code looking into other folders. I am bit puzzled on why it does this. mail_debug=yes did now show anything. Any more debug options for mdbox i might set to find out about its decisions? Flo -- Florian Lohoff f(a)zz.de Any sufficiently advanced technology is indistinguishable from magic.

3 5

Writing an custom imap command
by Ryan Beethe 10 May '21

10 May '21

I'm interested in writing a custom imap command that behaves a bit like IDLE but synchronizes some state that is specific to my mail client / mail server. I found that stateless commands were trivial to understand, and I really like the plugin pattern for registering custom commands. But I have a few questions on how to write a long-running command that I was not able to answer by reading through the code. This mailing list seems like the best place to ask them. For reference, the source code for my custom command is here: https://github.com/Splintermail/splintermail-client/blob/dev/server/xkeysyn… Thanks, Ryan ------ 1. Why does cmd-idle.c sometimes call client_command_free()? But sometimes it doesn't? For example, cmd_idle_continue() frees it in some branches but not others. That makes no sense to me; it seems like it should be based on your entrypoint (mailbox notify callback vs input callback vs timeout callback), not based on which branch of logic within that entrypoint. 2. Why does cmd-idle.c ever call client_destroy()? That seems like something that should be invoked only by the imap process, not by any command. It calls it in cmd-idle.c:idle_callback (which is a mailbox notify callback). It invokes it after idle_sync_now() when it detects that client->disconnected is set. Maybe that happens in imap_sync_init() or something? 3. Why does cmd-idle.c ever call client_disconnect()? That also seems like the responsibility of the imap process, and not any command. idle_client_input_more() detects when i_stream_read returns -1, meaning that the client has *already disconnected*. Then it calls client_disconnect(). I think this is the crazy part... the istream is effectively unique to the imap process, so it seems unreasonable that any command is responsible for cleaning it up; it should just always happen at the imap process level before exiting, right? 4. What does client_continue_pending_input() actually do, and under what conditions does it need to be called? There is one place that you *can't* call it; there is a section in imap-client.c:client_handle_input() that calls imap-client.c:client_handle_next_command(), which calls the cmd->func(). That makes sense; that's the input trigger for the command plugin, so maybe you only have to trigger it when you are receiving input that doesn't fit into the normal command args behavior. It has a comment that says "this function is called at the end of I/O callbacks (and only there)". It _is_ called by client_input() and by client_output(), but also by: - cmd-idle.c:idle_client_input (io_add_istream callback) - cmd-append.c:client_input_append (io_add_istream callback) - imap-search.c:cmd_search_more_callback (timeout_add callback) The first two cases seem to be the only io_add_istream() commands that even exist, so that explains them. I can't explain the imap-search.c case at all. Reading through it I have really no idea what client_continue_pending_input is really doing. My command has a DONE mechanic just like IDLE so I'm pretty sure I need to invoke this function, I'm just concerned I'm going to do it wrong if I don't understand the mechanics of it.

3 6

huge mdbox broken / Log synchronization error
by Florian Lohoff 10 May '21

10 May '21

Hi, its the second time in 6 Month i have issues with a huge mdbox. It broken in November and i restored from backup because force-resync twice didnt fix it. (And restore from borg-backup was MUCH faster than force-resync) This time i have heavy delivery into that mailbox (postfix concurrency 1) and i tried merging folders with doveadm move. The move froze and now i seem to have a broken mdbox: Errors are: May 05 10:21:09 lda(inbox(a)wasteland.rfc822.org): Error: Log synchronization error at seq=2736,offset=135540 for /var/vmail/wasteland.rfc822.org/inbox/mdbox/storage/dovecot.map.index: Extension record inc drops number below zero (uid=7757856, diff=-1, orig=0) trying root@pax:~# doveadm -D -v force-resync -u inbox(a)wasteland.rfc822.org \* now. Although this will mostly likely take 8-10 hours. Mailbox is 44GByte (Compressed mdbox) and 220K folders. This is dovecot on Debian/Stretch dovecot-core 1:2.2.27-3+deb9u7 dovecot-imapd 1:2.2.27-3+deb9u7 dovecot-ldap 1:2.2.27-3+deb9u7 dovecot-managesieved 1:2.2.27-3+deb9u7 dovecot-pop3d 1:2.2.27-3+deb9u7 dovecot-sieve 1:2.2.27-3+deb9u7 dovecot-solr 1:2.2.27-3+deb9u7 Flo -- Florian Lohoff f(a)zz.de Any sufficiently advanced technology is indistinguishable from magic.

3 10