- dovecot - dovecot.org

Re[5]: Replication weirdness
by Daniel Miller - CLOUD 05 Dec '21

05 Dec '21

Another update. I dug deeper into the mailboxes - and found the "subscriptions" and actual mailboxes weren't correct in all cases. I guess when I shifted to the explicit INBOX/ namespace not all the existing boxes migrated correctly. So...after manually correcting all the "subscription" files, and manually moving the duplicated "Archives" folders to the correct locations nearly all the errors have gone. I wish I'd gotten more inforrmative error messages, and processes certainly shouldn't have crashed, but since I obviously created the problem due to manually poking things and improper configuration I guess I can't complain too much. I still have problems using the "-N" flag for syncing - but things seem to be working with the multiple explicit "-n" namespaces. I do still have the locking error appearing during long-running syncs - I don't see why Dovecot doesn't know that it's already syncing a given user before trying to start a second process. Probably something else I setup wrong but I don't know what. -- Daniel

1 0

Re[4]: Replication weirdness
by Daniel Miller 04 Dec '21

04 Dec '21

And some more messages... Dec 3 15:10:58 bubba dovecot: doveadm(obfuscated)<1901><UGoeMgGkqmFtBwAAnbWsyw>: Error: Mailbox Sent sync: mailbox_rename failed: Can't rename mailbox while it has aliases Dec 3 15:10:58 bubba dovecot: doveadm(obfuscated)<1900><YVHxLACkqmFsBwAAnbWsyw>: Error: Duplicate mailbox GUID f4338038839caa613a1a0500b88bfabe for mailboxes INBOX/Sent Messages and INBOX/Sent - giving a new GUID bcf4f82702a4aa616c0700009db5accb to INBOX/Sent -- Daniel ------ Original Message ------ From: "Daniel Miller" <dmiller(a)amfes.com> To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org Sent: 12/3/2021 3:13:55 PM Subject: Re[3]: Replication weirdness >And... > >The user who has both a "Sent" and a "Sent Messages" now has: > >drwx------ 3 vmail mail 24 Dec 3 09:56 Sent >lrwxrwxrwx 1 vmail mail 4 Nov 30 17:51 'Sent Messages' -> Sent >drwx------ 3 vmail mail 24 Dec 3 15:10 'Sent Messages-temp-1' >drwx------ 3 vmail mail 24 Dec 3 15:10 'Sent >Messages-temp-fc30bd0a3a9aaa61c1180500b88bfabe' > >and I got the following errors: > >Dec 3 15:10:46 cloud1 dovecot: >doveadm(obfuscated)<336247><EMEQBvWjqmF3IQUAuIv6vg>: Error: Duplicate >mailbox GUID 6aae8c39f3a3aa615a0700009db5accb for mailboxes Sent and >Sent Messages-temp-1 - giving a new GUID >63481f29f6a3aa6177210500b88bfabe to Sent >Dec 3 15:10:50 cloud1 dovecot: >doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Panic: file >dsync-brain-mailbox.c: line 851 (dsync_brain_slave_recv_mailbox): >assertion failed: (memcmp(dsync_box->mailbox_guid, >local_dsync_box.mailbox_guid, sizeof(dsync_box->mailbox_guid)) == 0) >Dec 3 15:10:50 cloud1 dovecot: >doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Error: Raw >backtrace: #0 fatal_handler_real[0x7fde7fd20060] -> #1 >i_internal_fatal_handler[0x7fde7fd20190] -> #2 i_panic[0x7fde7fc731ff] >-> #3 dsync_brain_slave_recv_mailbox[0x55dde7b22900] -> #4 >dsync_brain_run[0x55dde7b20380] -> #5 >dsync_brain_run_io[0x55dde7b20b50] -> #6 >dsync_ibc_stream_input[0x55dde7b329c0] -> #7 >io_loop_call_io[0x7fde7fd36500] -> #8 >io_loop_handler_run_internal[0x7fde7fd37ac0] -> #9 >io_loop_handler_run[0x7fde7fd365c0] -> #10 io_loop_run[0x7fde7fd36740] >-> #11 cmd_dsync_server_run[0x55dde7b04f60] -> #12 >doveadm_mail_next_user[0x55dde7b06850] -> #13 >doveadm_cmd_ver2_to_mail_cmd_wrapper[0x55dde7b077e0] -> #14 >doveadm_cmd_run_ver2[0x55dde7b17f00] -> #15 >client_connection_tcp_input[0x55dde7b1c6b0] -> #16 >io_loop_call_io[0x7fde7fd36500] -> #17 >io_loop_handler_run_internal[0x7fde7fd37ac0] -> #18 >io_loop_handler_run[0x7fde7fd365c0] -> #19 io_loop_run[0x7fde7fd36740] >-> #20 master_service_run[0x7fde7fca87d0] -> #21 main[0x55dde7af7770] >-> #22 __libc_start_main[0x7fde7f8f9fc0] -> #23 _start[0x55dde7af78d0] >Dec 3 15:10:50 cloud1 dovecot: >doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Fatal: master: >service(doveadm): child 336245 killed with signal 6 (core dumped) >Dec 3 15:10:52 cloud1 dovecot: >doveadm(obfuscated)<336253><2VTpM/ujqmF9IQUAuIv6vg>: Error: Duplicate >mailbox GUID 63481f29f6a3aa6177210500b88bfabe for mailboxes INBOX/Sent >and INBOX/Sent Messages-temp-1 - giving a new GUID >cba35507fca3aa617d210500b88bfabe to INBOX/Sent >Dec 3 15:10:58 cloud1 dovecot: >doveadm(obfuscated)<336258><ykbQAAGkqmGCIQUAuIv6vg>: Error: Duplicate >mailbox GUID dc3b4434fba3aa61660700009db5accb for mailboxes Sent and >Sent Messages-temp-1 - giving a new GUID >60ad190102a4aa6182210500b88bfabe to Sent > >-- >Daniel > >------ Original Message ------ >From: "Daniel Miller" <dmiller(a)amfes.com> >To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org >Sent: 12/3/2021 2:42:12 PM >Subject: Re[2]: Replication weirdness > >>And...one more. >> >>I'm now seeing (again) messages like: >> >>Dec 3 14:29:14 cloud1 dovecot: >>doveadm(obfuscated)<334017><e3FHNjmaqmHBGAUAuIv6vg>: Error: Duplicate >>mailbox GUID bcb9ca36ae36aa617f0a00009db5accb for mailboxes INBOX/Sent >>Messages and INBOX/Sent - giving a new GUID >>fc30bd0a3a9aaa61c1180500b88bfabe to INBOX/Sent >>Dec 3 14:38:59 cloud1 dovecot: >>doveadm(obfuscated)<334394><an5KIoOcqmE6GgUAuIv6vg>: Error: Duplicate >>mailbox GUID fc30bd0a3a9aaa61c1180500b88bfabe for mailboxes INBOX/Sent >>Messages and INBOX/Sent - giving a new GUID >>f4338038839caa613a1a0500b88bfabe to INBOX/Sent >> >>Having one message for the initial sync I suppose is reasonable. A >>second...maybe? But I'm getting nervous I'm about to start seeing the >>endless temp folders again. >>-- >>Daniel >> >>------ Original Message ------ >>From: "Daniel Miller" <dmiller(a)amfes.com> >>To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org >>Sent: 12/3/2021 2:39:25 PM >>Subject: Re: Replication weirdness >> >>>Another item. >>> >>>Again, it may be a 2.3.13 issue and I'm now on 2.3.17. But...I had >>>problem when using the "-N" parameter for dsync. So - I just have >>>(had): >>> >>>replication_dsync_parameters = -d -l 30 -U -x INBOX/virtual -x >>>INBOX/shared >>> >>>Now that things are working - I wanted to have my other namespaces >>>sync as well. So I went to: >>> >>>replication_dsync_parameters = -d -l 30 -U -n INBOX -n INBOX/Archives >>>-n INBOX/Lists -x INBOX/virtual -x INBOX/shared >>> >>>This appears to be working (the sync is just starting)...but I'm >>>seeing lock errors in the logs such as: >>>Dec 3 14:34:24 bubba dovecot: >>>doveadm(dmiller(a)amfes.com)<31785><TV+0LlGbqmEpfAAAnbWsyw>: Error: >>>Couldn't lock /var/mail/amfes.com/dmiller/.dovecot-sync.lock: >>>fcntl(/var/mail/amfes.com/dmiller/.dovecot-sync.lock, write-lock, >>>F_SETLKW) locking failed: Timed out after 30 seconds (WRITE lock held >>>by pid 31373) >>> >>>Checking the pid in question I see it's actively syncing a folder in >>>my mailbox. So I'm guessing, purely guessing, that by having multiple >>>namespaces explicitly directed to sync Dovecot is trying to start a >>>sync process for each of those namespaces - but all of them share a >>>common lock and therefore only one operation is allowed at a time. >>> >>>Am I correct, and whether or not I am - how can I correct these >>>errors? Do I dare try going back to just "-N"? >>> >>>-- >>>Daniel >>> >>>------ Original Message ------ >>>From: "Daniel Miller" <dmiller(a)amfes.com> >>>To: dovecot(a)dovecot.org >>>Sent: 12/3/2021 2:16:28 PM >>>Subject: Replication weirdness >>> >>>>First, I have to say this. After configuring everything correctly - >>>>and that means *everything* correctly - Dovecot replication Just >>>>Works. I'm not sure how (yes I do - Timo & Co. Magic) - but it does. >>>>Real-time new sync is near instantaneous. >>>> >>>>Now the problem. Or the background for the problem. My primary >>>>server uses sdbox for primary storage, mdbox for archival storage, >>>>and fts-solr. I spun up a second server, using sdbox, mdbox, and >>>>fts-flatcurve. My namespaces are as defined below. As best I can >>>>tell (based on diff comparing two 'doveconf -n' outputs) my >>>>namespaces are the same on both servers. >>>> >>>>namespace archives { >>>> list = children >>>> location = mdbox:/var/mail/%d/%n/Archives/mdbox >>>> mailbox Unsorted { >>>> auto = no >>>> special_use = \Archive >>>> } >>>> prefix = INBOX/Archives/ >>>> separator = / >>>> subscriptions = no >>>> type = private >>>>} >>>>namespace inbox { >>>> alias_for = >>>> hidden = no >>>> inbox = yes >>>> list = yes >>>> location = >>>> mailbox "Deleted Messages" { >>>> auto = no >>>> autoexpunge = 30 days >>>> special_use = \Trash >>>> } >>>> mailbox Drafts { >>>> auto = subscribe >>>> special_use = \Drafts >>>> } >>>> mailbox Sent { >>>> auto = subscribe >>>> special_use = \Sent >>>> } >>>> mailbox Trash { >>>> auto = subscribe >>>> autoexpunge = 30 days >>>> special_use = \Trash >>>> } >>>> prefix = INBOX/ >>>> separator = / >>>> subscriptions = no >>>> type = private >>>>} >>>>namespace lists { >>>> list = children >>>> location = mdbox:/var/mail/%d/%n/Lists/mdbox >>>> prefix = INBOX/Lists/ >>>> separator = / >>>> subscriptions = no >>>> type = private >>>>} >>>>namespace subscriptions { >>>> hidden = yes >>>> list = no >>>> location = >>>> prefix = >>>> separator = / >>>> subscriptions = yes >>>> type = private >>>>} >>>>namespace usershares { >>>> list = yes >>>> location = sdbox:/var/mail/%%d/%%n/sdbox:NO-NOSELECT >>>> prefix = INBOX/shared/%%d/%%n/ >>>> separator = / >>>> subscriptions = no >>>> type = shared >>>>} >>>>namespace virtual { >>>> list = children >>>> location = virtual:/var/mail/%d/%n/virtual >>>> mailbox Flagged { >>>> comment = All my flagged messages >>>> special_use = \Flagged >>>> } >>>> prefix = INBOX/virtual/ >>>> separator = / >>>> subscriptions = no >>>>} >>>> >>>>I also have: >>>>plugin { >>>> mailbox_alias_new = Sent Messages >>>> mailbox_alias_new2 = Sent Items >>>> mailbox_alias_new3 = Deleted Messages >>>> mailbox_alias_old = Sent >>>> mailbox_alias_old2 = Sent >>>> mailbox_alias_old3 = Trash >>>>} >>>> >>>>This setup worked fine with my single server. Then I enabled >>>>replication - just on the primary. Dsync went to work (it seemed to >>>>take forever for the initial sync but that's what happens with large >>>>mailboxes and slow internet connections). >>>> >>>>The problem came up with certain subfolders. And I believe it only >>>>happens with subfolders that have spaces in their names. I had two >>>>user's mailboxes (under Sent), one of which had a "Sent Messages" >>>>symlink alias for "Sent", that started generating tens or hundreds >>>>of duplicates during sync. Fortunately those subfolders only had a >>>>few mails in them. But I had trees looking like: >>>> >>>>[...] (below is under /var/mail/domain/user/sdbox/mailboxes/Sent/) >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-2 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-3 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ade0400b88bfabe >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ad-temp-1 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-1 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2-temp-1-temp-1 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-3 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-4 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-5 >>>>Proposal >>>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-e2aa0f35c99ba961356500009db5accb >>>>[...] >>>> >>>>I kept stopping, cleaning up the folders, and re-starting - and they >>>>kept regenerating. I tried renaming the folders to eliminate the >>>>spaces and I think that helped in one case - for the others I just >>>>moved the folders outside of the mail area completely to let the >>>>sync finish. >>>> >>>>Now that it's been stable for a day or two - I enabled sync in the >>>>other direction. And after setting *all* the required parameters >>>>instead of just most of them...it's working. But...I'm nervous about >>>>moving the problem folders back over. I will say, if it makes any >>>>difference, my primary server *was* running version 2.3.13 and I >>>>just updated it to 2.3.17. The remote is also 2.3.17. >>>> >>>>-- >>>>Daniel

1 0

Re[3]: Replication weirdness
by Daniel Miller 04 Dec '21

04 Dec '21

And... The user who has both a "Sent" and a "Sent Messages" now has: drwx------ 3 vmail mail 24 Dec 3 09:56 Sent lrwxrwxrwx 1 vmail mail 4 Nov 30 17:51 'Sent Messages' -> Sent drwx------ 3 vmail mail 24 Dec 3 15:10 'Sent Messages-temp-1' drwx------ 3 vmail mail 24 Dec 3 15:10 'Sent Messages-temp-fc30bd0a3a9aaa61c1180500b88bfabe' and I got the following errors: Dec 3 15:10:46 cloud1 dovecot: doveadm(obfuscated)<336247><EMEQBvWjqmF3IQUAuIv6vg>: Error: Duplicate mailbox GUID 6aae8c39f3a3aa615a0700009db5accb for mailboxes Sent and Sent Messages-temp-1 - giving a new GUID 63481f29f6a3aa6177210500b88bfabe to Sent Dec 3 15:10:50 cloud1 dovecot: doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Panic: file dsync-brain-mailbox.c: line 851 (dsync_brain_slave_recv_mailbox): assertion failed: (memcmp(dsync_box->mailbox_guid, local_dsync_box.mailbox_guid, sizeof(dsync_box->mailbox_guid)) == 0) Dec 3 15:10:50 cloud1 dovecot: doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Error: Raw backtrace: #0 fatal_handler_real[0x7fde7fd20060] -> #1 i_internal_fatal_handler[0x7fde7fd20190] -> #2 i_panic[0x7fde7fc731ff] -> #3 dsync_brain_slave_recv_mailbox[0x55dde7b22900] -> #4 dsync_brain_run[0x55dde7b20380] -> #5 dsync_brain_run_io[0x55dde7b20b50] -> #6 dsync_ibc_stream_input[0x55dde7b329c0] -> #7 io_loop_call_io[0x7fde7fd36500] -> #8 io_loop_handler_run_internal[0x7fde7fd37ac0] -> #9 io_loop_handler_run[0x7fde7fd365c0] -> #10 io_loop_run[0x7fde7fd36740] -> #11 cmd_dsync_server_run[0x55dde7b04f60] -> #12 doveadm_mail_next_user[0x55dde7b06850] -> #13 doveadm_cmd_ver2_to_mail_cmd_wrapper[0x55dde7b077e0] -> #14 doveadm_cmd_run_ver2[0x55dde7b17f00] -> #15 client_connection_tcp_input[0x55dde7b1c6b0] -> #16 io_loop_call_io[0x7fde7fd36500] -> #17 io_loop_handler_run_internal[0x7fde7fd37ac0] -> #18 io_loop_handler_run[0x7fde7fd365c0] -> #19 io_loop_run[0x7fde7fd36740] -> #20 master_service_run[0x7fde7fca87d0] -> #21 main[0x55dde7af7770] -> #22 __libc_start_main[0x7fde7f8f9fc0] -> #23 _start[0x55dde7af78d0] Dec 3 15:10:50 cloud1 dovecot: doveadm(obfuscated)<336245><HrHeOPOjqmF1IQUAuIv6vg>: Fatal: master: service(doveadm): child 336245 killed with signal 6 (core dumped) Dec 3 15:10:52 cloud1 dovecot: doveadm(obfuscated)<336253><2VTpM/ujqmF9IQUAuIv6vg>: Error: Duplicate mailbox GUID 63481f29f6a3aa6177210500b88bfabe for mailboxes INBOX/Sent and INBOX/Sent Messages-temp-1 - giving a new GUID cba35507fca3aa617d210500b88bfabe to INBOX/Sent Dec 3 15:10:58 cloud1 dovecot: doveadm(obfuscated)<336258><ykbQAAGkqmGCIQUAuIv6vg>: Error: Duplicate mailbox GUID dc3b4434fba3aa61660700009db5accb for mailboxes Sent and Sent Messages-temp-1 - giving a new GUID 60ad190102a4aa6182210500b88bfabe to Sent -- Daniel ------ Original Message ------ From: "Daniel Miller" <dmiller(a)amfes.com> To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org Sent: 12/3/2021 2:42:12 PM Subject: Re[2]: Replication weirdness >And...one more. > >I'm now seeing (again) messages like: > >Dec 3 14:29:14 cloud1 dovecot: >doveadm(obfuscated)<334017><e3FHNjmaqmHBGAUAuIv6vg>: Error: Duplicate >mailbox GUID bcb9ca36ae36aa617f0a00009db5accb for mailboxes INBOX/Sent >Messages and INBOX/Sent - giving a new GUID >fc30bd0a3a9aaa61c1180500b88bfabe to INBOX/Sent >Dec 3 14:38:59 cloud1 dovecot: >doveadm(obfuscated)<334394><an5KIoOcqmE6GgUAuIv6vg>: Error: Duplicate >mailbox GUID fc30bd0a3a9aaa61c1180500b88bfabe for mailboxes INBOX/Sent >Messages and INBOX/Sent - giving a new GUID >f4338038839caa613a1a0500b88bfabe to INBOX/Sent > >Having one message for the initial sync I suppose is reasonable. A >second...maybe? But I'm getting nervous I'm about to start seeing the >endless temp folders again. >-- >Daniel > >------ Original Message ------ >From: "Daniel Miller" <dmiller(a)amfes.com> >To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org >Sent: 12/3/2021 2:39:25 PM >Subject: Re: Replication weirdness > >>Another item. >> >>Again, it may be a 2.3.13 issue and I'm now on 2.3.17. But...I had >>problem when using the "-N" parameter for dsync. So - I just have >>(had): >> >>replication_dsync_parameters = -d -l 30 -U -x INBOX/virtual -x >>INBOX/shared >> >>Now that things are working - I wanted to have my other namespaces >>sync as well. So I went to: >> >>replication_dsync_parameters = -d -l 30 -U -n INBOX -n INBOX/Archives >>-n INBOX/Lists -x INBOX/virtual -x INBOX/shared >> >>This appears to be working (the sync is just starting)...but I'm >>seeing lock errors in the logs such as: >>Dec 3 14:34:24 bubba dovecot: >>doveadm(dmiller(a)amfes.com)<31785><TV+0LlGbqmEpfAAAnbWsyw>: Error: >>Couldn't lock /var/mail/amfes.com/dmiller/.dovecot-sync.lock: >>fcntl(/var/mail/amfes.com/dmiller/.dovecot-sync.lock, write-lock, >>F_SETLKW) locking failed: Timed out after 30 seconds (WRITE lock held >>by pid 31373) >> >>Checking the pid in question I see it's actively syncing a folder in >>my mailbox. So I'm guessing, purely guessing, that by having multiple >>namespaces explicitly directed to sync Dovecot is trying to start a >>sync process for each of those namespaces - but all of them share a >>common lock and therefore only one operation is allowed at a time. >> >>Am I correct, and whether or not I am - how can I correct these >>errors? Do I dare try going back to just "-N"? >> >>-- >>Daniel >> >>------ Original Message ------ >>From: "Daniel Miller" <dmiller(a)amfes.com> >>To: dovecot(a)dovecot.org >>Sent: 12/3/2021 2:16:28 PM >>Subject: Replication weirdness >> >>>First, I have to say this. After configuring everything correctly - >>>and that means *everything* correctly - Dovecot replication Just >>>Works. I'm not sure how (yes I do - Timo & Co. Magic) - but it does. >>>Real-time new sync is near instantaneous. >>> >>>Now the problem. Or the background for the problem. My primary server >>>uses sdbox for primary storage, mdbox for archival storage, and >>>fts-solr. I spun up a second server, using sdbox, mdbox, and >>>fts-flatcurve. My namespaces are as defined below. As best I can tell >>>(based on diff comparing two 'doveconf -n' outputs) my namespaces are >>>the same on both servers. >>> >>>namespace archives { >>> list = children >>> location = mdbox:/var/mail/%d/%n/Archives/mdbox >>> mailbox Unsorted { >>> auto = no >>> special_use = \Archive >>> } >>> prefix = INBOX/Archives/ >>> separator = / >>> subscriptions = no >>> type = private >>>} >>>namespace inbox { >>> alias_for = >>> hidden = no >>> inbox = yes >>> list = yes >>> location = >>> mailbox "Deleted Messages" { >>> auto = no >>> autoexpunge = 30 days >>> special_use = \Trash >>> } >>> mailbox Drafts { >>> auto = subscribe >>> special_use = \Drafts >>> } >>> mailbox Sent { >>> auto = subscribe >>> special_use = \Sent >>> } >>> mailbox Trash { >>> auto = subscribe >>> autoexpunge = 30 days >>> special_use = \Trash >>> } >>> prefix = INBOX/ >>> separator = / >>> subscriptions = no >>> type = private >>>} >>>namespace lists { >>> list = children >>> location = mdbox:/var/mail/%d/%n/Lists/mdbox >>> prefix = INBOX/Lists/ >>> separator = / >>> subscriptions = no >>> type = private >>>} >>>namespace subscriptions { >>> hidden = yes >>> list = no >>> location = >>> prefix = >>> separator = / >>> subscriptions = yes >>> type = private >>>} >>>namespace usershares { >>> list = yes >>> location = sdbox:/var/mail/%%d/%%n/sdbox:NO-NOSELECT >>> prefix = INBOX/shared/%%d/%%n/ >>> separator = / >>> subscriptions = no >>> type = shared >>>} >>>namespace virtual { >>> list = children >>> location = virtual:/var/mail/%d/%n/virtual >>> mailbox Flagged { >>> comment = All my flagged messages >>> special_use = \Flagged >>> } >>> prefix = INBOX/virtual/ >>> separator = / >>> subscriptions = no >>>} >>> >>>I also have: >>>plugin { >>> mailbox_alias_new = Sent Messages >>> mailbox_alias_new2 = Sent Items >>> mailbox_alias_new3 = Deleted Messages >>> mailbox_alias_old = Sent >>> mailbox_alias_old2 = Sent >>> mailbox_alias_old3 = Trash >>>} >>> >>>This setup worked fine with my single server. Then I enabled >>>replication - just on the primary. Dsync went to work (it seemed to >>>take forever for the initial sync but that's what happens with large >>>mailboxes and slow internet connections). >>> >>>The problem came up with certain subfolders. And I believe it only >>>happens with subfolders that have spaces in their names. I had two >>>user's mailboxes (under Sent), one of which had a "Sent Messages" >>>symlink alias for "Sent", that started generating tens or hundreds of >>>duplicates during sync. Fortunately those subfolders only had a few >>>mails in them. But I had trees looking like: >>> >>>[...] (below is under /var/mail/domain/user/sdbox/mailboxes/Sent/) >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-2 >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-3 >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ade0400b88bfabe >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ad-temp-1 >>>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-1 >>>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2 >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2-temp-1-temp-1 >>>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-3 >>>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-4 >>>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-5 >>>Proposal >>>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-e2aa0f35c99ba961356500009db5accb >>>[...] >>> >>>I kept stopping, cleaning up the folders, and re-starting - and they >>>kept regenerating. I tried renaming the folders to eliminate the >>>spaces and I think that helped in one case - for the others I just >>>moved the folders outside of the mail area completely to let the sync >>>finish. >>> >>>Now that it's been stable for a day or two - I enabled sync in the >>>other direction. And after setting *all* the required parameters >>>instead of just most of them...it's working. But...I'm nervous about >>>moving the problem folders back over. I will say, if it makes any >>>difference, my primary server *was* running version 2.3.13 and I just >>>updated it to 2.3.17. The remote is also 2.3.17. >>> >>>-- >>>Daniel

1 0

Re[2]: Replication weirdness
by Daniel Miller 03 Dec '21

03 Dec '21

And...one more. I'm now seeing (again) messages like: Dec 3 14:29:14 cloud1 dovecot: doveadm(obfuscated)<334017><e3FHNjmaqmHBGAUAuIv6vg>: Error: Duplicate mailbox GUID bcb9ca36ae36aa617f0a00009db5accb for mailboxes INBOX/Sent Messages and INBOX/Sent - giving a new GUID fc30bd0a3a9aaa61c1180500b88bfabe to INBOX/Sent Dec 3 14:38:59 cloud1 dovecot: doveadm(obfuscated)<334394><an5KIoOcqmE6GgUAuIv6vg>: Error: Duplicate mailbox GUID fc30bd0a3a9aaa61c1180500b88bfabe for mailboxes INBOX/Sent Messages and INBOX/Sent - giving a new GUID f4338038839caa613a1a0500b88bfabe to INBOX/Sent Having one message for the initial sync I suppose is reasonable. A second...maybe? But I'm getting nervous I'm about to start seeing the endless temp folders again. -- Daniel ------ Original Message ------ From: "Daniel Miller" <dmiller(a)amfes.com> To: "Daniel Miller" <dmiller(a)amfes.com>; dovecot(a)dovecot.org Sent: 12/3/2021 2:39:25 PM Subject: Re: Replication weirdness >Another item. > >Again, it may be a 2.3.13 issue and I'm now on 2.3.17. But...I had >problem when using the "-N" parameter for dsync. So - I just have >(had): > >replication_dsync_parameters = -d -l 30 -U -x INBOX/virtual -x >INBOX/shared > >Now that things are working - I wanted to have my other namespaces sync >as well. So I went to: > >replication_dsync_parameters = -d -l 30 -U -n INBOX -n INBOX/Archives >-n INBOX/Lists -x INBOX/virtual -x INBOX/shared > >This appears to be working (the sync is just starting)...but I'm seeing >lock errors in the logs such as: >Dec 3 14:34:24 bubba dovecot: >doveadm(dmiller(a)amfes.com)<31785><TV+0LlGbqmEpfAAAnbWsyw>: Error: >Couldn't lock /var/mail/amfes.com/dmiller/.dovecot-sync.lock: >fcntl(/var/mail/amfes.com/dmiller/.dovecot-sync.lock, write-lock, >F_SETLKW) locking failed: Timed out after 30 seconds (WRITE lock held >by pid 31373) > >Checking the pid in question I see it's actively syncing a folder in my >mailbox. So I'm guessing, purely guessing, that by having multiple >namespaces explicitly directed to sync Dovecot is trying to start a >sync process for each of those namespaces - but all of them share a >common lock and therefore only one operation is allowed at a time. > >Am I correct, and whether or not I am - how can I correct these errors? >Do I dare try going back to just "-N"? > >-- >Daniel > >------ Original Message ------ >From: "Daniel Miller" <dmiller(a)amfes.com> >To: dovecot(a)dovecot.org >Sent: 12/3/2021 2:16:28 PM >Subject: Replication weirdness > >>First, I have to say this. After configuring everything correctly - >>and that means *everything* correctly - Dovecot replication Just >>Works. I'm not sure how (yes I do - Timo & Co. Magic) - but it does. >>Real-time new sync is near instantaneous. >> >>Now the problem. Or the background for the problem. My primary server >>uses sdbox for primary storage, mdbox for archival storage, and >>fts-solr. I spun up a second server, using sdbox, mdbox, and >>fts-flatcurve. My namespaces are as defined below. As best I can tell >>(based on diff comparing two 'doveconf -n' outputs) my namespaces are >>the same on both servers. >> >>namespace archives { >> list = children >> location = mdbox:/var/mail/%d/%n/Archives/mdbox >> mailbox Unsorted { >> auto = no >> special_use = \Archive >> } >> prefix = INBOX/Archives/ >> separator = / >> subscriptions = no >> type = private >>} >>namespace inbox { >> alias_for = >> hidden = no >> inbox = yes >> list = yes >> location = >> mailbox "Deleted Messages" { >> auto = no >> autoexpunge = 30 days >> special_use = \Trash >> } >> mailbox Drafts { >> auto = subscribe >> special_use = \Drafts >> } >> mailbox Sent { >> auto = subscribe >> special_use = \Sent >> } >> mailbox Trash { >> auto = subscribe >> autoexpunge = 30 days >> special_use = \Trash >> } >> prefix = INBOX/ >> separator = / >> subscriptions = no >> type = private >>} >>namespace lists { >> list = children >> location = mdbox:/var/mail/%d/%n/Lists/mdbox >> prefix = INBOX/Lists/ >> separator = / >> subscriptions = no >> type = private >>} >>namespace subscriptions { >> hidden = yes >> list = no >> location = >> prefix = >> separator = / >> subscriptions = yes >> type = private >>} >>namespace usershares { >> list = yes >> location = sdbox:/var/mail/%%d/%%n/sdbox:NO-NOSELECT >> prefix = INBOX/shared/%%d/%%n/ >> separator = / >> subscriptions = no >> type = shared >>} >>namespace virtual { >> list = children >> location = virtual:/var/mail/%d/%n/virtual >> mailbox Flagged { >> comment = All my flagged messages >> special_use = \Flagged >> } >> prefix = INBOX/virtual/ >> separator = / >> subscriptions = no >>} >> >>I also have: >>plugin { >> mailbox_alias_new = Sent Messages >> mailbox_alias_new2 = Sent Items >> mailbox_alias_new3 = Deleted Messages >> mailbox_alias_old = Sent >> mailbox_alias_old2 = Sent >> mailbox_alias_old3 = Trash >>} >> >>This setup worked fine with my single server. Then I enabled >>replication - just on the primary. Dsync went to work (it seemed to >>take forever for the initial sync but that's what happens with large >>mailboxes and slow internet connections). >> >>The problem came up with certain subfolders. And I believe it only >>happens with subfolders that have spaces in their names. I had two >>user's mailboxes (under Sent), one of which had a "Sent Messages" >>symlink alias for "Sent", that started generating tens or hundreds of >>duplicates during sync. Fortunately those subfolders only had a few >>mails in them. But I had trees looking like: >> >>[...] (below is under /var/mail/domain/user/sdbox/mailboxes/Sent/) >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-2 >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-3 >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ade0400b88bfabe >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ad-temp-1 >>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-1 >>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2 >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2-temp-1-temp-1 >>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-3 >>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-4 >>Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-5 >>Proposal >>Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-e2aa0f35c99ba961356500009db5accb >>[...] >> >>I kept stopping, cleaning up the folders, and re-starting - and they >>kept regenerating. I tried renaming the folders to eliminate the >>spaces and I think that helped in one case - for the others I just >>moved the folders outside of the mail area completely to let the sync >>finish. >> >>Now that it's been stable for a day or two - I enabled sync in the >>other direction. And after setting *all* the required parameters >>instead of just most of them...it's working. But...I'm nervous about >>moving the problem folders back over. I will say, if it makes any >>difference, my primary server *was* running version 2.3.13 and I just >>updated it to 2.3.17. The remote is also 2.3.17. >> >>-- >>Daniel

1 0

Re: Replication weirdness
by Daniel Miller 03 Dec '21

03 Dec '21

Another item. Again, it may be a 2.3.13 issue and I'm now on 2.3.17. But...I had problem when using the "-N" parameter for dsync. So - I just have (had): replication_dsync_parameters = -d -l 30 -U -x INBOX/virtual -x INBOX/shared Now that things are working - I wanted to have my other namespaces sync as well. So I went to: replication_dsync_parameters = -d -l 30 -U -n INBOX -n INBOX/Archives -n INBOX/Lists -x INBOX/virtual -x INBOX/shared This appears to be working (the sync is just starting)...but I'm seeing lock errors in the logs such as: Dec 3 14:34:24 bubba dovecot: doveadm(dmiller(a)amfes.com)<31785><TV+0LlGbqmEpfAAAnbWsyw>: Error: Couldn't lock /var/mail/amfes.com/dmiller/.dovecot-sync.lock: fcntl(/var/mail/amfes.com/dmiller/.dovecot-sync.lock, write-lock, F_SETLKW) locking failed: Timed out after 30 seconds (WRITE lock held by pid 31373) Checking the pid in question I see it's actively syncing a folder in my mailbox. So I'm guessing, purely guessing, that by having multiple namespaces explicitly directed to sync Dovecot is trying to start a sync process for each of those namespaces - but all of them share a common lock and therefore only one operation is allowed at a time. Am I correct, and whether or not I am - how can I correct these errors? Do I dare try going back to just "-N"? -- Daniel ------ Original Message ------ From: "Daniel Miller" <dmiller(a)amfes.com> To: dovecot(a)dovecot.org Sent: 12/3/2021 2:16:28 PM Subject: Replication weirdness >First, I have to say this. After configuring everything correctly - and >that means *everything* correctly - Dovecot replication Just Works. I'm >not sure how (yes I do - Timo & Co. Magic) - but it does. Real-time new >sync is near instantaneous. > >Now the problem. Or the background for the problem. My primary server >uses sdbox for primary storage, mdbox for archival storage, and >fts-solr. I spun up a second server, using sdbox, mdbox, and >fts-flatcurve. My namespaces are as defined below. As best I can tell >(based on diff comparing two 'doveconf -n' outputs) my namespaces are >the same on both servers. > >namespace archives { > list = children > location = mdbox:/var/mail/%d/%n/Archives/mdbox > mailbox Unsorted { > auto = no > special_use = \Archive > } > prefix = INBOX/Archives/ > separator = / > subscriptions = no > type = private >} >namespace inbox { > alias_for = > hidden = no > inbox = yes > list = yes > location = > mailbox "Deleted Messages" { > auto = no > autoexpunge = 30 days > special_use = \Trash > } > mailbox Drafts { > auto = subscribe > special_use = \Drafts > } > mailbox Sent { > auto = subscribe > special_use = \Sent > } > mailbox Trash { > auto = subscribe > autoexpunge = 30 days > special_use = \Trash > } > prefix = INBOX/ > separator = / > subscriptions = no > type = private >} >namespace lists { > list = children > location = mdbox:/var/mail/%d/%n/Lists/mdbox > prefix = INBOX/Lists/ > separator = / > subscriptions = no > type = private >} >namespace subscriptions { > hidden = yes > list = no > location = > prefix = > separator = / > subscriptions = yes > type = private >} >namespace usershares { > list = yes > location = sdbox:/var/mail/%%d/%%n/sdbox:NO-NOSELECT > prefix = INBOX/shared/%%d/%%n/ > separator = / > subscriptions = no > type = shared >} >namespace virtual { > list = children > location = virtual:/var/mail/%d/%n/virtual > mailbox Flagged { > comment = All my flagged messages > special_use = \Flagged > } > prefix = INBOX/virtual/ > separator = / > subscriptions = no >} > >I also have: >plugin { > mailbox_alias_new = Sent Messages > mailbox_alias_new2 = Sent Items > mailbox_alias_new3 = Deleted Messages > mailbox_alias_old = Sent > mailbox_alias_old2 = Sent > mailbox_alias_old3 = Trash >} > >This setup worked fine with my single server. Then I enabled >replication - just on the primary. Dsync went to work (it seemed to >take forever for the initial sync but that's what happens with large >mailboxes and slow internet connections). > >The problem came up with certain subfolders. And I believe it only >happens with subfolders that have spaces in their names. I had two >user's mailboxes (under Sent), one of which had a "Sent Messages" >symlink alias for "Sent", that started generating tens or hundreds of >duplicates during sync. Fortunately those subfolders only had a few >mails in them. But I had trees looking like: > >[...] (below is under /var/mail/domain/user/sdbox/mailboxes/Sent/) >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-2 >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-3 >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ade0400b88bfabe >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ad-temp-1 >Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-1 >Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2 >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2-temp-1-temp-1 >Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-3 >Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-4 >Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-5 >Proposal >Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-e2aa0f35c99ba961356500009db5accb >[...] > >I kept stopping, cleaning up the folders, and re-starting - and they >kept regenerating. I tried renaming the folders to eliminate the spaces >and I think that helped in one case - for the others I just moved the >folders outside of the mail area completely to let the sync finish. > >Now that it's been stable for a day or two - I enabled sync in the >other direction. And after setting *all* the required parameters >instead of just most of them...it's working. But...I'm nervous about >moving the problem folders back over. I will say, if it makes any >difference, my primary server *was* running version 2.3.13 and I just >updated it to 2.3.17. The remote is also 2.3.17. > >-- >Daniel

1 0

Replication weirdness
by Daniel Miller 03 Dec '21

03 Dec '21

First, I have to say this. After configuring everything correctly - and that means *everything* correctly - Dovecot replication Just Works. I'm not sure how (yes I do - Timo & Co. Magic) - but it does. Real-time new sync is near instantaneous. Now the problem. Or the background for the problem. My primary server uses sdbox for primary storage, mdbox for archival storage, and fts-solr. I spun up a second server, using sdbox, mdbox, and fts-flatcurve. My namespaces are as defined below. As best I can tell (based on diff comparing two 'doveconf -n' outputs) my namespaces are the same on both servers. namespace archives { list = children location = mdbox:/var/mail/%d/%n/Archives/mdbox mailbox Unsorted { auto = no special_use = \Archive } prefix = INBOX/Archives/ separator = / subscriptions = no type = private } namespace inbox { alias_for = hidden = no inbox = yes list = yes location = mailbox "Deleted Messages" { auto = no autoexpunge = 30 days special_use = \Trash } mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Sent { auto = subscribe special_use = \Sent } mailbox Trash { auto = subscribe autoexpunge = 30 days special_use = \Trash } prefix = INBOX/ separator = / subscriptions = no type = private } namespace lists { list = children location = mdbox:/var/mail/%d/%n/Lists/mdbox prefix = INBOX/Lists/ separator = / subscriptions = no type = private } namespace subscriptions { hidden = yes list = no location = prefix = separator = / subscriptions = yes type = private } namespace usershares { list = yes location = sdbox:/var/mail/%%d/%%n/sdbox:NO-NOSELECT prefix = INBOX/shared/%%d/%%n/ separator = / subscriptions = no type = shared } namespace virtual { list = children location = virtual:/var/mail/%d/%n/virtual mailbox Flagged { comment = All my flagged messages special_use = \Flagged } prefix = INBOX/virtual/ separator = / subscriptions = no } I also have: plugin { mailbox_alias_new = Sent Messages mailbox_alias_new2 = Sent Items mailbox_alias_new3 = Deleted Messages mailbox_alias_old = Sent mailbox_alias_old2 = Sent mailbox_alias_old3 = Trash } This setup worked fine with my single server. Then I enabled replication - just on the primary. Dsync went to work (it seemed to take forever for the initial sync but that's what happens with large mailboxes and slow internet connections). The problem came up with certain subfolders. And I believe it only happens with subfolders that have spaces in their names. I had two user's mailboxes (under Sent), one of which had a "Sent Messages" symlink alias for "Sent", that started generating tens or hundreds of duplicates during sync. Fortunately those subfolders only had a few mails in them. But I had trees looking like: [...] (below is under /var/mail/domain/user/sdbox/mailboxes/Sent/) Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-2 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-1-temp-f80b1a00ce9aa961a86-temp-3 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ade0400b88bfabe Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-023fa4271c9ca9611ad-temp-1 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-1 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-2-temp-1-temp-1 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-3 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-4 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-5 Proposal Requests-temp-c6e003375e64a961c93d00009db5accb-temp-2-temp-e2aa0f35c99ba961356500009db5accb [...] I kept stopping, cleaning up the folders, and re-starting - and they kept regenerating. I tried renaming the folders to eliminate the spaces and I think that helped in one case - for the others I just moved the folders outside of the mail area completely to let the sync finish. Now that it's been stable for a day or two - I enabled sync in the other direction. And after setting *all* the required parameters instead of just most of them...it's working. But...I'm nervous about moving the problem folders back over. I will say, if it makes any difference, my primary server *was* running version 2.3.13 and I just updated it to 2.3.17. The remote is also 2.3.17. -- Daniel

1 0

Searching 30 GB mailbox
by Einar Bjarni Halldórsson 03 Dec '21

03 Dec '21

Hi, We're migrating our mailboxes from Zimbra to dovecot, running on FreeBSD 12.2. We're using mdbox and solr for fts. dovecot version 2.3.17. One of our mailboxes gets a bcc of every outgoing mail from our system and it currently holds ~4.5 million messages taking 30 GB. One of the ways we use the mailbox is that when outgoing mail is sent, we store the Message-ID in our database, and in our admin interface we can open the mail and it's fetched from IMAP by doing a 'SEARCH HEADER Message-ID <MSG_ID>'. In Zimbra this was reasonably fast, but after migrating the mailbox to dovecot it's 30 seconds which I think we can reduce. After turning on mail_debug I see this in our log https://pastebin.com/kP9H7gSB Looks like solr finishes searching instantly, then there's ~30 seconds of silence in the logs, and then more log lines about fetching data from mail cache. The same thing happens if I use telnet and just issue a 'SEARCH HEADER...' command. How can I find out what dovecot is doing in those 30 seconds? .einar

5 14

Expunged message reappeared
by Claudio Corvino 03 Dec '21

03 Dec '21

Hi, I have two IMAP/LMTP Dovecot server in replica (version 2.3.4.1), I use LDAP/AD for /userdb, /replica is working, but sometimes I get these errors into log: Dec 3 15:47:15 xxx dovecot: imap(xxx)<28251><TOSxmj7SPRYloY5/>: Warning: Maildir /mnt/mail-storage-lv0007/xxx/Maildir: Expunged message reappeared, giving a new UID (old uid=233140, file=1638540323.M588041P27708.xxx,S=84376,W=85507:2,) The user delete the message and then the message reappears into mail client after one second. Does anybody knows how can I fix it? Thanks in advance Regards

1 1

Re: new bee needs starter docs
by Gene Heskett 03 Dec '21

03 Dec '21

On Fri, 3 Dec, 2021 at 3:50 AM, Christian Mack <christian.mack(a)uni-konstanz.de> wrote: To: dovecot(a)dovecot.org Hello What you need is probably 'doveadm sync'. Check its manual with man doveadm-sync I did, that's equ to my climbing El Capitan at 87 yo. 'taint gonna happen. So I think I'll try to make my old method work, so back to the kde-pim list. Kind regards, Christian Mack Thank you Christian

1 0

Issue with SCRAM-SHA Authorization
by Thomas Schmid 03 Dec '21

03 Dec '21

Hi, I was debugging a bug report for my sieve editor implementation concerning an issue with SCRAM-SHA Authorization. But I am a bit unsure about my findings. It seems to be a server side bug. But I am wondering if I missed something. What puzzles me a bit is that SCRAM-SHA is out since ages and obviously no one ran into this issue. Which feels odd. When I try to connect to a dovecot server with enabled Authorization, then SCRAM SHA1 or SHA256 fail with a channel binding error. Authorization via SASL PLAIN works perfectly fine. So I digged into the logs. The trace is below also my findings/conclusion. The username and authorization in the trace are set to "user" the password is "pencil". Nov 24 14:00:06 auth: Debug: client in: AUTH 1 SCRAM-SHA-256 service=sieve secured=tlssession=sI9yRonRZISsEQAB lip=172.17.0.2 rip=172.17.0.1 lport=4190 rport=33892 resp=bixhPXVzZXIsbj11c2VyLHI9ZmEzZGY1NjNlZjczZTY3YjQzZThhZWRiZjUzNGI1NWIxNzIwNzU3OThjZmJiMjExNmMyMTNkMWM4NDE4MmZkOQ== (previous base64 data may contain sensitive data) Nov 24 14:00:06 auth: Debug: passwd-file(user,172.17.0.1,<sI9yRonRZISsEQAB>): Performing passdb lookup Nov 24 14:00:06 auth: Debug: passwd-file(user,172.17.0.1,<sI9yRonRZISsEQAB>): lookup: user=user file=/etc/dovecot/users Nov 24 14:00:06 auth: Debug: passwd-file(user,172.17.0.1,<sI9yRonRZISsEQAB>): Generating SCRAM-SHA-256 from user 'user', password 'pencil' Nov 24 14:00:06 auth: Debug: passwd-file(user,172.17.0.1,<sI9yRonRZISsEQAB>): Finished passdb lookup Nov 24 14:00:06 auth: Debug: Credentials: 343039362c326b3934364452546c326431765a37434b6d556c32513d3d2c46444d364f7173577035464c446e394151666554316547585045427a47566d6965673842427331456d37633d2c79766e5a4169376250392f59706c4a71597872356a79794f7a6e4c664730667636485155325a7a6975376b3d Nov 24 14:00:06 auth: Debug: client passdb out: CONT 1 cj1mYTNkZjU2M2VmNzNlNjdiNDNlOGFlZGJmNTM0YjU1YjE3MjA3NTc5OGNmYmIyMTE2YzIxM2QxYzg0MTgyZmQ5J2Q9NCskV2NuWEFVTnZxOU1EZENgM2UheVguXFw3O2JgKlg0X29gKDtBXnJrTi1xUmQ2IXgiQX5+eGU8ZlJHWSxzPTJrOTQ2RFJUbDJkMXZaN0NLbVVsMlE9PSxpPTQwOTY= Nov 24 14:00:06 auth: Debug: client in: CONT 1 Yz1iaXhoUFhWelpYSXMscj1mYTNkZjU2M2VmNzNlNjdiNDNlOGFlZGJmNTM0YjU1YjE3MjA3NTc5OGNmYmIyMTE2YzIxM2QxYzg0MTgyZmQ5J2Q9NCskV2NuWEFVTnZxOU1EZENgM2UheVguXFw3O2JgKlg0X29gKDtBXnJrTi1xUmQ2IXgiQX5+eGU8ZlJHWSxwPUcvZGZWUUlGZy9NMkpSMlpEMXM0cms4MS9jTmFMa0tuMzZFYzFlTTN1enc9 (previous base64 data may contain sensitive data) Nov 24 14:00:06 auth: Info: scram-sha-256(user,172.17.0.1,<sI9yRonRZISsEQAB>): Invalid channel binding data Nov 24 14:00:06 auth: Debug: auth(user,172.17.0.1,<sI9yRonRZISsEQAB>): Auth request finished Nov 24 14:00:08 auth: Debug: client passdb out: FAIL 1 user=user Nov 24 14:00:08 managesieve-login: Info: Disconnected: Aborted login by logging out (auth failed, 1 attempts in 2 secs): user=<user>, method=SCRAM-SHA-256, rip=172.17.0.1, lip=172.17.0.2, TLS, session=<sI9yRonRZISsEQAB> Nov 24 14:00:08 managesieve-login: Debug: SSL alert: close notify The matching trace from the client, a sieve editor (https://github.com/thsmi/sieve) is as follows: [15:000:06.192 kw53213a-qc7kf99m1lp] Client -> Server: AUTHENTICATE "SCRAM-SHA-256" "bixhPXVzZXIsbj11c2VyLHI9ZmEzZGY1NjNlZjczZTY3YjQzZThhZWRiZjUzNGI1NWIxNzIwNzU3OThjZmJiMjExNmMyMTNkMWM4NDE4MmZkOQ==" [15:000:06.202 kw53213a-qc7kf99m1lp] Server -> Client "cj1mYTNkZjU2M2VmNzNlNjdiNDNlOGFlZGJmNTM0YjU1YjE3MjA3NTc5OGNmYmIyMTE2YzIxM2QxYzg0MTgyZmQ5J2Q9NCskV2NuWEFVTnZxOU1EZENgM2UheVguXFw3O2JgKlg0X29gKDtBXnJrTi1xUmQ2IXgiQX5+eGU8ZlJHWSxzPTJrOTQ2RFJUbDJkMXZaN0NLbVVsMlE9PSxpPTQwOTY=" [15:000:06.209 kw53213a-qc7kf99m1lp] Client -> Server: "Yz1iaXhoUFhWelpYSXMscj1mYTNkZjU2M2VmNzNlNjdiNDNlOGFlZGJmNTM0YjU1YjE3MjA3NTc5OGNmYmIyMTE2YzIxM2QxYzg0MTgyZmQ5J2Q9NCskV2NuWEFVTnZxOU1EZENgM2UheVguXFw3O2JgKlg0X29gKDtBXnJrTi1xUmQ2IXgiQX5+eGU8ZlJHWSxwPUcvZGZWUUlGZy9NMkpSMlpEMXM0cms4MS9jTmFMa0tuMzZFYzFlTTN1enc9" [15:000:08.215 kw53213a-qc7kf99m1lp] Server -> Client NO "Authentication failed." According to the RFC (https://datatracker.ietf.org/doc/html/rfc5802) the initial request is defined as: (("p=" cb-name) / "n" / "y") "," [ authzid ] "," client-first-message-bare This means the decoded message from the trace is: n,a=user,n=user,r=fa3df563ef73e67b43e8aedbf534b55b172075798cfbb2116c213d1c84182fd9 The final request (which is rejected by the server with the binding error) is defined as : client-final-message-without-proof = channel-binding "," nonce [","extensions] or client-final-message = client-final-message-without-proof "," proof So the request from the trace decodes into: c=bixhPXVzZXIs,r=fa3df563ef73e67b43e8aedbf534b55b172075798cfbb2116c213d1c84182fd9'd=4+$WcnXAUNvq9MDdC`3e!yX.\\7;b`*X4_o`(;A^rkN-qRd6!x"A~~xe<fRGY,p=G/dfVQIFg/M2JR2ZD1s4rk81/cNaLkKn36Ec1eM3uzw= The channel-binding and cbind-input part are defined as: channel-binding = "c=" base64(cbind-input) cbind-input = (("p=" cb-name) / "n" / "y") "," [ authzid ] "," [ cbind-data ] where cbind-data has to be absent by definition as dovecot does not support channel binding so no "p=" is possible and thus no cbind-data. This means c=bixhPXVzZXI decodes into. n,a=user, And this is where it gets strange. The dovecot code section which throws the error, implements the following: https://github.com/dovecot/core/blob/a5209c83c3a82386c94d466eec5fea394973e8… cbind_input = t_strconcat(request->gs2_cbind_flag, ",,", NULL); str = t_str_new(MAX_BASE64_ENCODED_SIZE(strlen(cbind_input))); str_append(str, "c="); base64_encode(cbind_input, strlen(cbind_input), str); if (strcmp(fields[0], str_c(str)) != 0) { *error_r = "Invalid channel binding data"; return FALSE; } As you can see it uses the bind flag which was saved to the request. But instead of the authzid, it uses always an hardcoded empty string. Thus cbind-input is "n,," instead of "n,a=user," and results in the request being rejected with an "Invalid channel binding data". Which is on the one hand a funny message because dovecot does not support channel binding at all, as describe in https://github.com/dovecot/core/blob/a5209c83c3a82386c94d466eec5fea394973e8… but it also on the other hand somehow correct because cbind-input string does not match. Which is an illegal state during channel binding negotiation which should not happen. As said previously, it looks to me like a server side bug. Or did I miss something special case in the RFC? Kind Regards Thomas Schmid

2 1