February 2022 - dovecot

Too many wait in auth process
by ismael.tanguy＠univ-brest.fr 18 Feb '22

18 Feb '22

Hello, I'm currently benchmarking new hardware aimed to serve around 70k users For now, our IMAP server have 13k users. To run imaptest, I've spwan some bench clients. Each bench client can run imaptest with 1000 clients. More than 1000 clients will load CPU of this bench client imaptest command (command are chosen from usage stat on our other IMAP servers): imaptest host=xxxxx port=xxx userfile=userfile mbox=/root/dovecot-crlf pass=sxxxx seed=123 clients=1000 select=194 uidfetch=94 noop=70 status=82 append=49 fetch=276 list=12 store=19 expunge=22 msubs=4 search=4 logout=1 delete=81 no_pipelining With one bench client, everything runs smoothly. # ps aux | grep dovecot | awk '{print $11,$12,$13,$14,$15,$16,$17,$18}' | sort | uniq -c 1 anvil: [221 connections] (anvil) 1 auth: [13 wait, 0 passdb, 0 userdb] (auth) 1 dovecot/config 1 dovecot/imap 84 dovecot/imap-login 1 dovecot/log 20 dovecot/pop3-login 1 grep dovecot 1 stats: [1307 connections] (stats) When a second instance bench instance start imaptest, clients of first and second instance begin to stall : 1400 stalled for 20 secs in command: 1 LOGIN"fakeuser644@mailbench...." "password" And : # ps aux | grep dovecot | awk '{print $11,$12,$13,$14,$15,$16,$17,$18}' | sort | uniq -c 1 anvil: [221 connections] (anvil) 1 auth: [1227 wait, 0 passdb, 0 userdb] (auth) 1 dovecot/config 1 dovecot/imap 37 dovecot/imap-login 1 dovecot/log 20 dovecot/pop3-login 1 grep dovecot 1 stats: [680 connections] (stats) Every auth go in wait, number of connection decreases. Using mysql or a password file give same results. I have used different values for service_count with also no success. I think my use of imaptest could be false. My understanding of service auth is limited for now because I'm quite new to Dovecot (I have previously worked with Cyrus). Thank you for every hints. Ismaël Tanguy

12 13

Shared mailbox visible but not readable
by Kees van Vloten 17 Feb '22

17 Feb '22

After the previous thread, I am now able to see / list the structure of a shared mailbox but cannot see the messages. doveadm acl get -u test2 INBOX ID Global Rights user=test1 admin create delete expunge insert lookup post read write write-deleted write-seen dovecot -n # 2.3.13 (89f716dc2): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.13 (cdd19fe3) # OS: Linux 5.10.0-10-amd64 x86_64 Debian 11.2 ext4 # Hostname: server.example.com auth_debug = yes auth_default_realm = EXAMPLE.COM auth_gssapi_hostname = server.example.com auth_krb5_keytab = /etc/keytab/dovecot.keytab auth_master_user_separator = * auth_mechanisms = gssapi gss-spnego plain auth_realms = EXAMPLE.COM auth_verbose = yes first_valid_gid = 986 first_valid_uid = 990 hostname = server.example.com imap_client_workarounds = tb-extra-mailbox-sep imap_max_line_length = 2 M login_greeting = Dovecot ready. mail_debug = yes mail_gid = 986 mail_location = maildir:/srv/mail/vmail/example.com/%n/store:LAYOUT=fs:FULLDIRNAME=0_Folder… mail_plugins = zlib notify push_notification listescape acl mail_shared_explicit_inbox = yes mail_uid = 990 namespace { hidden = no list = children location = maildir:/srv/mail/vmail/example.com/%%n/store:LAYOUT=fs:FULLDIRNAME=0_Folde… prefix = shared~%%n~ separator = ~ subscriptions = no type = shared } namespace inbox { hidden = no inbox = yes list = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Inbox { auto = subscribe } mailbox Junk { auto = subscribe special_use = \Junk } mailbox Sent { auto = subscribe special_use = \Sent } mailbox Trash { auto = subscribe special_use = \Trash } prefix = separator = ~ subscriptions = yes type = private } passdb { args = username_format=%u /etc/dovecot/master-users driver = passwd-file master = yes } passdb { args = /etc/dovecot/ldap_user_to_principal.conf.ext driver = ldap pass = yes } passdb { args = nopassword=y allow_nets=127.0.0.1/32 driver = static } passdb { driver = pam } plugin { acl = vfile acl_defaults_from_inbox = yes acl_shared_dict = file:/srv/mail/dovecot/lib/shared-mailboxes.db acl_user = %n autocreate = Trash autocreate2 = Drafts autocreate3 = Sent autosubscribe = Trash autosubscribe2 = Drafts autosubscribe3 = Sent } protocols = " imap lmtp submission" service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } service imap-login { inet_listener imap { port = 0 } inet_listener imap_local { address = 127.0.0.1 port = 144 ssl = no } inet_listener imaps { port = 993 ssl = yes } process_min_avail = 1 } service indexer-worker { vsz_limit = 2 G } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service submission-login { inet_listener submission { port = 465 ssl = yes } } ssl = required ssl_cert = </etc/dovecot/private/dovecot.pem ssl_cipher_list = EECDH+AESGCM:EDH+AESGCM ssl_client_ca_dir = /etc/ssl/certs ssl_curve_list = X25519:secp521r1:secp384r1:prime256v1 ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it ssl_min_protocol = TLSv1.2 submission_client_workarounds = whitespace-before-path submission_relay_host = localhost userdb { args = /etc/dovecot/ldap_user_domain.conf.ext driver = ldap result_success = continue } userdb { args = uid=vmail gid=vmail home=/srv/mail/vmail allow_all_users=yes driver = static } protocol lmtp { mail_plugins = zlib notify push_notification listescape acl } protocol lda { mail_plugins = zlib notify push_notification listescape acl } protocol imap { mail_max_userip_connections = 50 mail_plugins = zlib notify push_notification listescape acl imap_acl } Server-side logging: Feb 17 18:19:46 server dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=wnsM+TnYeNt/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=144#011rport=56184#011resp=<hidden> Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1(a)example.com,127.0.0.1,<wnsM+TnYeNt/AAAB>): Performing passdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1(a)example.com,127.0.0.1,<wnsM+TnYeNt/AAAB>): pass search: base=OU=User Accounts,OU=Interactive Users,OU=Groupware,DC=example,DC=com scope=subtree filter=(&(objectClass=user)(sAMAccountName=test1)(memberOf:1.2.840.113556.1.4.1941:=CN=mail_user-example.com,OU=Mail Domains,OU=Groups,DC=example,DC=com)(!(userAccountControl:1.2.840.113556.1.4.803:=2))) fields=userPrincipalName Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1(a)example.com,127.0.0.1,<wnsM+TnYeNt/AAAB>): result: userPrincipalName=test1(a)example.com; userPrincipalName unused Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1(a)example.com,127.0.0.1,<wnsM+TnYeNt/AAAB>): username changed test1(a)example.com -> test1 Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Finished passdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Performing passdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): lookup Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): allow_nets: Matching for network 127.0.0.1/32 Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Finished passdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: auth(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Auth request finished Feb 17 18:19:46 server dovecot: auth: Debug: client passdb out: OK#0111#011user=test1#011k5principals=test1(a)example.com Feb 17 18:19:46 server dovecot: auth: Debug: master in: REQUEST#011674496513#011982757#0111#011bdc4ed95a66c86ed9e287682de2cc297#011session_pid=982760#011request_auth_token Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Performing userdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): user search: base=OU=User Accounts,OU=Interactive Users,OU=Groupware,DC=example,DC=com scope=subtree filter=(&(objectClass=user)(sAMAccountName=test1)(memberOf:1.2.840.113556.1.4.1941:=CN=mail_user-,OU=Mail Domains,OU=Groups,DC=example,DC=com)(!(userAccountControl:1.2.840.113556.1.4.803:=2))) fields= Feb 17 18:19:46 server dovecot: auth: Debug: auth client connected (pid=982759) Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): no fields returned by the server Feb 17 18:19:46 server dovecot: auth: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): unknown user Feb 17 18:19:46 server dovecot: auth: Debug: ldap(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Finished userdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Performing userdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: static(test1,127.0.0.1,<wnsM+TnYeNt/AAAB>): Finished userdb lookup Feb 17 18:19:46 server dovecot: auth: Debug: master userdb out: USER#011674496513#011test1#011uid=990#011gid=986#011home=/srv/mail/vmail#011auth_mech=PLAIN#011auth_token=7f5013248866ebfbfb636b8de817aad6ac5af767 Feb 17 18:19:46 server dovecot: imap-login: Login: user=<test1>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=982760, secured, session=<wnsM+TnYeNt/AAAB> Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: Effective uid=990, gid=986, home=/srv/mail/vmail Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: Namespace inbox: type=private, prefix=, sep=~, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/srv/mail/vmail/example.com/test1/store:LAYOUT=fs:FULLDIRN… Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: fs: root=/srv/mail/vmail/example.com/test1/store, index=/srv/mail/vmail/example.com/test1/index, indexpvt=, control=/srv/mail/vmail/example.com/test1/control, inbox=, alt= Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: initializing backend with data: vfile Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: acl username = test1 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: owner = 1 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl vfile: Global ACLs disabled Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: Namespace : type=shared, prefix=shared~%n~, sep=~, inbox=no, hidden=no, list=children, subscriptions=no location=maildir:/srv/mail/vmail/example.com/%n/store:LAYOUT=fs:FULLDIRNAME… Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt= Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: fts: Indexes disabled for namespace 'shared~%n~' Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: initializing backend with data: vfile Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: acl username = test1 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: owner = 0 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl vfile: Global ACLs disabled Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: fs: root=/srv/mail/vmail/example.com/test2/INBOX/store, index=, indexpvt=/srv/mail/vmail/example.com/test1/index_shared/test2/INBOX, control=/srv/mail/vmail/example.com/test2/INBOX/control, inbox=, alt= Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: initializing backend with data: vfile Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: acl username = test2/INBOX Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: owner = 1 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl vfile: Global ACLs disabled Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: fs: root=/srv/mail/vmail/example.com/test2/INBOX/store, index=, indexpvt=/srv/mail/vmail/example.com/test1/index_shared/test2/INBOX, control=/srv/mail/vmail/example.com/test2/INBOX/control, inbox=, alt= Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: initializing backend with data: vfile Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: acl username = test1 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl: owner = 0 Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: acl vfile: Global ACLs disabled Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: Mailbox shared~test2~INBOX: Mailbox opened because: SELECT Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Logged out in=245 out=1711 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Client-side logging: S[0x55ae80a7bb00]: * OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE LITERAL+ STARTTLS AUTH=GSSAPI AUTH=GSS-SPNEGO AUTH=PLAIN] Dovecot ready. C[0x55ae808c12d0]: 1 login "test1" "" S[0x55ae80a7bb00]: 1 OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY STATUS=SIZE SAVEDATE LITERAL+ NOTIFY SPECIAL-USE ACL RIGHTS=texk] Logged in C[0x55ae808c12d0]: 2 capability S[0x55ae80a7bb00]: * CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY STATUS=SIZE SAVEDATE LITERAL+ NOTIFY SPECIAL-USE ACL RIGHTS=texk S[0x55ae80a7bb00]: 2 OK Capability completed (0.001 + 0.000 secs). C[0x55ae808c12d0]: 3 ID ("x-originating-ip" "192.168.10.106") S[0x55ae80a7bb00]: * ID ("name" "Dovecot") S[0x55ae80a7bb00]: 3 OK ID completed (0.001 + 0.001 secs). C[0x55ae808c12d0]: 4 namespace S[0x55ae80a7bb00]: * NAMESPACE (("" "~")) (("shared~" "~")) NIL S[0x55ae80a7bb00]: 4 OK Namespace completed (0.001 + 0.000 secs). C[0x55ae808c12d0]: 5 LIST "" "" S[0x55ae80a7bb00]: * LIST (\Noselect) "~" "" S[0x55ae80a7bb00]: 5 OK List completed (0.001 + 0.001 secs). C[0x55ae808c12d0]: 6 select "INBOX" S[0x55ae80a7bb00]: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft) S[0x55ae80a7bb00]: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags permitted. S[0x55ae80a7bb00]: * 1 EXISTS S[0x55ae80a7bb00]: * 0 RECENT S[0x55ae80a7bb00]: * OK [UIDVALIDITY 1637177527] UIDs valid S[0x55ae80a7bb00]: * OK [UIDNEXT 2] Predicted next UID S[0x55ae80a7bb00]: * OK [HIGHESTMODSEQ 10] Highest S[0x55ae80a7bb00]: 6 OK [READ-WRITE] Select completed (0.001 + 0.000 secs). C[0x55ae808c12d0]: 7 UID SEARCH (UNSEEN NOT DELETED) S[0x55ae80a7bb00]: * SEARCH S[0x55ae80a7bb00]: 7 OK Search completed (0.001 + 0.001 secs). C[0x55ae808c12d0]: 8 select "shared~test2~INBOX" S[0x55ae80a7bb00]: * OK [CLOSED] Previous mailbox closed. S[0x55ae80a7bb00]: 8 NO [CANNOT] Invalid mailbox name 'shared~test2~INBOX': Missing namespace prefix 'shared~test2/INBOX~' (0.001 + 0.001 secs). C[0x55ae808c12d0]: 9 logout S[0x55ae80a7bb00]: * BYE Logging out This issue I am facing is this: 8 NO [CANNOT] Invalid mailbox name 'shared~test2~INBOX': Missing namespace prefix 'shared~test2/INBOX~' The server-side seems to think everything is fine: Feb 17 18:19:46 server dovecot: imap(test1)<982760><wnsM+TnYeNt/AAAB>: Debug: Mailbox shared~test2~INBOX: Mailbox opened because: SELECT But I do not get to see any messages in test2's shared mailbox. How to debug this? Or better: how to fix it :-) ?? - Kees

2 2

mail-crypt and mbox format
by cincodemayo_67＠yahoo.com 17 Feb '22

17 Feb '22

Hi, My Dovecot server of many years has been set up to use mbox email folders. I want to implement mail-crypt and after banging my head against a wall for a few days trying to get mail-crypt to work I decided to try it against a test instance of my server that I reset to use Maildir format and mail-crypt worked instantly. Does mail-crypt work with mbox format mail folders, or am I wasting my time unless I switch over to Maildir? The documentation at https://doc.dovecot.org/configuration_manual/mail_crypt_plugin/ doesn't explicitly say Maildir is required. Thanks in advance, Doug

5 9

Mailbox sharing not working
by Kees van Vloten 17 Feb '22

17 Feb '22

Hi Team, I am trying to setup mailbox sharing. But although user test2 shares INBOX with test1, it is not visible for user1. doveadm acl get -u test2 INBOX ID Global Rights user=test1 admin create delete expunge insert lookup post read write write-deleted write-seen cat /srv/mail/dovecot/lib/shared-mailboxes.db shared/shared-boxes/user/test1/test2(a)example.com 1 Log output: Feb 16 20:12:42 server dovecot: imap-login: Login: user=<test1(a)example.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=900367, secured, session=<mDkSbyfYotF/AAAB> Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Loading modules from directory: /usr/lib/dovecot/modules Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_fts_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_listescape_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_push_notification_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_zlib_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib21_fts_xapian_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Effective uid=990, gid=986, home=/srv/mail/vmail Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Namespace inbox: type=private, prefix=, sep=~, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/srv/mail/vmail/example.com/test1/store:LAYOUT=fs:FULLDIRN… Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: fs: root=/srv/mail/vmail/example.com/test1/store, index=/srv/mail/vmail/example.com/test1/index, indexpvt=, control=/srv/mail/vmail/example.com/test1/control, inbox=, alt= Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: acl: initializing backend with data: vfile Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: Mailbox INBOX~example.com: Mailbox opened because: SELECT Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/INBOX/example.com/0_FolderContent/dovecot-acl not found Feb 16 20:12:42 server dovecot: imap(test1(a)example.com)<900367><mDkSbyfYotF/AAAB>: Logged out in=136 out=1584 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Feb 16 20:12:43 server dovecot: imap-login: Login: user=<test1(a)example.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=900369, secured, session=<82gfbyfYuNF/AAAB> <removed lines> Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: Namespace inbox: type=private, prefix=, sep=~, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/srv/mail/vmail/example.com/test1/store:LAYOUT=fs:FULLDIRN… Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: fs: root=/srv/mail/vmail/example.com/test1/store, index=/srv/mail/vmail/example.com/test1/index, indexpvt=, control=/srv/mail/vmail/example.com/test1/control, inbox=, alt= Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl: initializing backend with data: vfile Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl: acl username = test1(a)example.com Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl: owner = 1 Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: Global ACLs disabled Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: Namespace : type=shared, prefix=shared~%u~, sep=~, inbox=no, hidden=no, list=no, subscriptions=no location=maildir:/srv/mail/vmail/example.com/%n/store:LAYOUT=fs:FULLDIRNAME… Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt= Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: fts: Indexes disabled for namespace 'shared~%u~' Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl: initializing backend with data: vfile Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl: acl username = test1(a)example.com Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: reading file /srv/mail/vmail/example.com/test1/store/INBOX/0_FolderContent/dovecot-acl Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/Drafts/0_FolderContent/dovecot-acl not found Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/Junk/0_FolderContent/dovecot-acl not found Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/Trash/0_FolderContent/dovecot-acl not found Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/Sent/0_FolderContent/dovecot-acl not found Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: acl vfile: file /srv/mail/vmail/example.com/test1/store/INBOX/example.com/0_FolderContent/dovecot-acl not found Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Debug: Namespace shared~: Using permissions from : mode=0700 gid=default Feb 16 20:12:43 server dovecot: imap(test1(a)example.com)<900369><82gfbyfYuNF/AAAB>: Logged out in=130 out=1518 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Dovecot -n: # 2.3.13 (89f716dc2): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.13 (cdd19fe3) # OS: Linux 5.10.0-10-amd64 x86_64 Debian 11.2 ext4 # Hostname: server.example.com auth_default_realm = EXAMPLE.COM auth_gssapi_hostname = server.example.com auth_krb5_keytab = /etc/keytab/dovecot.keytab auth_master_user_separator = * auth_mechanisms = gssapi gss-spnego plain auth_realms = EXAMPLE.COM first_valid_gid = 601 first_valid_uid = 601 hostname = server.example.com imap_client_workarounds = tb-extra-mailbox-sep imap_max_line_length = 2 M login_greeting = Dovecot ready. mail_debug = yes mail_gid = 986 mail_location = maildir:/srv/mail/vmail/example.com/%n/store:LAYOUT=fs:FULLDIRNAME=0_Folder… mail_plugins = zlib notify push_notification listescape acl mail_shared_explicit_inbox = yes mail_uid = 990 namespace { hidden = no list = no location = maildir:/srv/mail/vmail/example.com/%%n/store:LAYOUT=fs:FULLDIRNAME=0_Folde… prefix = shared~%%u~ separator = ~ subscriptions = no type = shared } namespace inbox { hidden = no inbox = yes list = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Inbox { auto = subscribe } mailbox Junk { auto = subscribe special_use = \Junk } mailbox Sent { auto = subscribe special_use = \Sent } mailbox Trash { auto = subscribe special_use = \Trash } prefix = separator = ~ subscriptions = yes type = private } passdb { args = username_format=%u /etc/dovecot/master-users driver = passwd-file master = yes } passdb { args = /etc/dovecot/ldap_user_to_principal.conf.ext driver = ldap pass = yes } passdb { args = nopassword=y allow_nets=127.0.0.1/32 driver = static } passdb { driver = pam } plugin { acl = vfile acl_defaults_from_inbox = yes acl_shared_dict = file:/srv/mail/dovecot/lib/shared-mailboxes.db acl_user = %u autocreate = Trash autocreate2 = Drafts autocreate3 = Sent autosubscribe = Trash autosubscribe2 = Drafts autosubscribe3 = Sent listescape_char = \ } postmaster_address = admin(a)example.com protocols = " imap lmtp submission" service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } service imap-login { inet_listener imap { port = 0 } inet_listener imap_local { address = 127.0.0.1 port = 144 ssl = no } inet_listener imaps { port = 993 ssl = yes } process_min_avail = 1 } service indexer-worker { vsz_limit = 2 G } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service submission-login { inet_listener submission { port = 465 ssl = yes } } ssl = required ssl_cert = </etc/dovecot/private/dovecot.pem ssl_cipher_list = EECDH+AESGCM:EDH+AESGCM ssl_client_ca_dir = /etc/ssl/certs ssl_curve_list = X25519:secp521r1:secp384r1:prime256v1 ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it ssl_min_protocol = TLSv1.2 submission_client_workarounds = whitespace-before-path submission_relay_host = localhost userdb { args = /etc/dovecot/ldap_list_users.conf.ext driver = ldap result_success = continue } userdb { args = /etc/dovecot/ldap_user_domain.conf.ext driver = ldap result_success = continue } userdb { args = uid=vmail gid=vmail home=/srv/mail/vmail allow_all_users=yes driver = static } protocol lmtp { mail_plugins = zlib notify push_notification listescape acl } protocol lda { mail_plugins = zlib notify push_notification listescape acl } protocol imap { mail_max_userip_connections = 50 mail_plugins = zlib notify push_notification listescape acl imap_acl } Is there anything obviously wrong in the config? I suspect a mismatch between %u and %n somewhere but don't know how to figure out the culprit. How can I get more relevant debug log output about namespaces / mailbox sharing? Or can I run commands to check validity? - Kees

2 10

Replications ERROR
by Günther J. Niederwimmer 16 Feb '22

16 Feb '22

Hello, Can any Help me to find out the Problem with "sync failed" I have all disabled only one user is in the moment running? doveadm replicator status '*' username priority fast sync full sync success sync failed gjn(a)example.com none 00:01:47 23:37:43 - y gjn none 00:01:47 23:42:43 - y Could it be a Problem with this doveadm user '*' gjn(a)example.com What is the way to become logs what is going wrong ? Could it be, I have Problems with the Dovecot Variables in the LDAP Config ? Thanks very match for a answer, -- mit freundlichen Grüßen / best regards Günther J. Niederwimmer

2 3

Memory problems with config service
by Víctor Rubiella Monfort 16 Feb '22

16 Feb '22

Hi all, I'm having problems with memory in config service. I increased vsz_limit to 10GB but continue with this errors when try to reload or restart dovecot: config: Panic: data stack: Out of memory when allocating 2147483688 bytes master: Error: service(config): command startup failed, throttling for 2 secs config: Fatal: master: service(config): child 5512 killed with signal 6 (core dumps disabled) Dovecot has a lot of certificates TLS configured (SNI) (about 3k), but if I check the size of all of them is aprox 170MB on disk.Why does it need so much memory to boot? Is normal? service config { vsz_limit = {{ vszlimit }} }

2 1

mail.error listen_fd(7): Error: 22 46530 BYE
by Juerg Reimann 14 Feb '22

14 Feb '22

Hi there, What do the following logs mean and how do I resolve the problem? 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 22 46519 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 26 46529 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 26 46531 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 22 46530 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 22 46532 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 22 46537 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 26 46535 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 22 46536 BYE 2022-02-14T12:44:24+01:00 localhost dovecot: [ID 702911 mail.error] listen_fd(7): Error: 26 46534 BYE Thanks for your help, Juerg

1 0

JWT tokens, timestamps and doubles (microseconds)
by Aleš Krajník 14 Feb '22

14 Feb '22

Hi all, I am having troubles with OAuth2 setup with local introspection of JWT tokens. This happens, when the JWT tokens contain timestamps as doubles, with microseconds, for example with the following payload: { "aud": "caf65d650022e3eb7cce518e7526a39f", "jti": "8291efed41d2ce65ec5c59a4cbcaa285f2ca37d5b2785da56de66adbd1b8eef65495bc 599be5ac56", "iat": 1644833538.793359, "nbf": 1644833538.79336, "exp": 1644833838.773605, "sub": "ales(a)example.com", "scope": "email" } Such a JWT token produces the following error: dovecot_1 | Feb 14 10:10:46 auth: Info: oauth2(ales(a)example.com,192.168.224.2,<xWZFoffXYujAqOAC>): oauth2 failed: Local validation failed: Malformed 'exp' field According to the RFC, the timestamps seem to be allowed to contain non- integer values: NumericDate A JSON numeric value representing the number of seconds from 1970- 01-01T00:00:00Z UTC until the specified UTC date/time, ignoring leap seconds. This is equivalent to the IEEE Std 1003.1, 2013 Edition [POSIX.1] definition "Seconds Since the Epoch", in which each day is accounted for by exactly 86400 seconds, other than that non-integer values can be represented. See RFC 3339 [RFC3339] for details regarding date/times in general and UTC in particular. (https://datatracker.ietf.org/doc/html/draft-ietf-oauth-json-web-token-32#se…) After removing the fractions, the token works well. This seems to be happening here: https://github.com/dovecot/core/blob/master/src/lib-oauth2/oauth2-jwt.c#L41 If you agree for this to be a bug, can I fill in a bug report somewhere? Thank you! Best, Aleš

2 1

wondering if I configured sieve vacation correctly
by Marc 14 Feb '22

14 Feb '22

I have a user who feels compelled to use the vacation as autoreply to confirm that a message has been received. The down side is of course, that if spam/abuse messages get through the spam filters, this can get 'messy'. Currently I am getting these ndr's as postmaster(?). But I was not actually expecting this. I would expect that the mailbox with the autoreply would get this report. The vacation is configured like this[1], my question is. What am I doing wrong that this ndr is not ending up in the users mailbox? Can it be the from is not correctly configured/set at the time the vacation message is being sent? [1] require ["vacation"]; # rule:[cccccccccc] if true { vacation :addresses "test(a)test.com" :from "test(a)test.com" text: dddddddddddddd } [2] Return-Path: <> Received: from aaaaa (localhost [127.0.0.1]) by aaaaa (8.14.7/8.14.7) with ESMTP id 21BDgaPj014029 (version=TLSv1/SSLv3 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO) for <postyk(a)hm.edu>; Fri, 11 Feb 2022 14:42:36 +0100 Received: (from root@localhost) by aaaaa (8.14.7/8.14.7/Submit) id 21BDgamD014028 for postyk(a)hm.edu; Fri, 11 Feb 2022 14:42:36 +0100 X-Sieve: Pigeonhole Sieve 0.4.24 (124e06aa) Message-ID: <dovecot-sieve-1644586956-19320-0@bbbb> Date: Fri, 11 Feb 2022 14:42:36 +0100 From: test(a)test.com To: <postyk(a)hm.edu>

1 1

Backup procedures
by Jorge Bastos 13 Feb '22

13 Feb '22

Howdy, I have a particular situation where I have about 5 users using a large account in IMAP, and I have the need to backup the account daily or weekly or so. I was thinking about to copy the whole directory, each email is a file, it could probably work, but the dovecot index files would be damaged/wrong. Is there a tool that could perform a backup (ex: yesterday), and when I inserted that backup, it just insert the emails and folders that were deleted today? Thanks in advanced, Jorge

5 8