Problem with initial sync on new mailbox in a replicated setup
ppq at tuta.io
ppq at tuta.io
Wed Apr 6 08:35:50 UTC 2022
Hello,
I run a two-node replicated setup with director + dovecot and replication between the two nodes.
The setup is a couple of years old and has been working properly until recently, so I suspect some type of regression.
I'm having an issue with replication and merging of newly created mailboxes. Old mailboxes work properly.
When creating a new mailbox, the two nodes will not replicate and sync the new mailbox. I have to manually "merge" the mailbox via a "doveadm sync -1f..." command, after which all works properly. This has not been the case in the past, so I'm trying to debug the issue.
When syncing manually, I get the following error:
-----------------------------
# doveadm -v sync -df -u 'testaccount at mydomain.ext'
doveadm(testaccount at mydomain.ext)<38041><wl3tAQ5LTWKZlAAAxdOQ8Q>: Warning: Mailbox changes caused a desync. You may want to run dsync again: Remote lost mailbox GUID 6bfcbb2f92484d624b890000c5d390f1 (maybe it was just deleted?)
----------------------------
I have to sync once with a one-way merge using sync -1f and after the sync works properly.
My setup is running Dovecot CE 2:2.3.18-4+debian11 from the dovecot.org repository installed on debian bullseye. The replicaiton is dove via TCP plaintext connection.
Below I'm attaching some debug logs, for both sync -1f and sync -f.
Is this a normal behavior or is this a bug ?
Kind regards,
Dave
---- CUT ----
# doveadm -v sync -df -u 'testaccount at mydomain.ext'
Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm
2022-04-06 10:12:17 Debug: Loading modules from directory: /usr/lib/dovecot/modules
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/lib02_lazy_expunge_plugin.so
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so
2022-04-06 10:12:17 Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so
2022-04-06 10:12:17 Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): Started passdb lookup
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb: Connecting
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb (pid=181,uid=0): Client connected (fd=9)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): auth PASS input: user=testaccount at mydomain.ext
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): Finished passdb lookup (user=testaccount at mydomain.ext )
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): Started userdb lookup
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): auth USER input: testaccount at mydomain.ext home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount> mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx> uid=5000 gid=5000 quota_rule=*:storage=0B sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): Finished userdb lookup (username=testaccount at mydomain.ext home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount> mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx> uid=5000 gid=5000 quota_rule=*:storage=0B sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: Added userdb setting: mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: Added userdb setting: plugin/quota_rule=*:storage=0B
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><>: Debug: Added userdb setting: plugin/sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Effective uid=5000, gid=5000, home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: acl: No acl_shared_dict setting - shared mailbox listing is disabled
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Quota root: name=user backend=dict args=:file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Quota rule: root=user mailbox=* bytes=0 messages=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Quota rule: root=user mailbox=EXPUNGED ignored
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Quota grace: root=user bytes=0 (10%)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: quota-dict: user=testaccount at mydomain.ext, uri=file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>, noenforcing=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): dict created (uri=file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>, base_dir=/var/run/dovecot)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: maildir++: root=/var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>, index=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/idx>, indexpvt=, control=, inbox=/var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>, alt=
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot.acl
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: acl: acl username = testaccount at mydomain.ext
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: acl: owner = 1
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot.acl
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: brain M: Namespace has location maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'INBOX' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/dovecot-acl <http://mydomain.ext/testaccount/Maildir/dovecot-acl> not found
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox '' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Trash' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl> not found
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Sent' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl> not found
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Junk' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl> not found
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Drafts' matches global ACL pattern '*'
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl> not found
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext): Debug: Namespace : Using permissions from /var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>: mode=0700 gid=default
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Local mailbox tree: INBOX guid=08b6a62792484d624b890000c5d390f1 uid_validity=1649232018 uid_next=2 subs=no last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Drafts guid=6bfcbb2f92484d624b890000c5d390f1 uid_validity=1649232022 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Junk guid=6afcbb2f92484d624b890000c5d390f1 uid_validity=1649232021 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Sent guid=69fcbb2f92484d624b890000c5d390f1 uid_validity=1649232020 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Trash guid=68fcbb2f92484d624b890000c5d390f1 uid_validity=1649232019 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: INBOX guid=4d70ba2389484d628fa91300660b22f9 uid_validity=1649232013 uid_next=1 subs=no last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Junk guid=4c70ba2389484d628fa91300660b22f9 uid_validity=1649232012 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Drafts guid=4b70ba2389484d628fa91300660b22f9 uid_validity=1649232011 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Sent guid=4a70ba2389484d628fa91300660b22f9 uid_validity=1649232010 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Trash guid=4970ba2389484d628fa91300660b22f9 uid_validity=1649232009 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Mailbox Drafts: local=6bfcbb2f92484d624b890000c5d390f1/0/1, remote=4b70ba2389484d628fa91300660b22f9/0/1: GUIDs conflict - will be merged later
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Mailbox INBOX: local=08b6a62792484d624b890000c5d390f1/0/1, remote=4d70ba2389484d628fa91300660b22f9/0/1: GUIDs conflict - will be merged later
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Mailbox Junk: local=6afcbb2f92484d624b890000c5d390f1/0/1, remote=4c70ba2389484d628fa91300660b22f9/0/1: GUIDs conflict - will be merged later
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Mailbox Sent: local=69fcbb2f92484d624b890000c5d390f1/0/1, remote=4a70ba2389484d628fa91300660b22f9/0/1: GUIDs conflict - will be merged later
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Mailbox Trash: local=68fcbb2f92484d624b890000c5d390f1/0/1, remote=4970ba2389484d628fa91300660b22f9/0/1: GUIDs conflict - will be merged later
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Drafts: Rotated transaction log /var/vmail-local/mydomain.ext/testaccount/idx/.Drafts/dovecot.index.log <http://mydomain.ext/testaccount/idx/.Drafts/dovecot.index.log> (seq=11, reset=yes)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox INBOX: Rotated transaction log /var/vmail-local/mydomain.ext/testaccount/idx/.INBOX/dovecot.index.log <http://mydomain.ext/testaccount/idx/.INBOX/dovecot.index.log> (seq=11, reset=yes)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Junk: Rotated transaction log /var/vmail-local/mydomain.ext/testaccount/idx/.Junk/dovecot.index.log <http://mydomain.ext/testaccount/idx/.Junk/dovecot.index.log> (seq=11, reset=yes)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Sent: Rotated transaction log /var/vmail-local/mydomain.ext/testaccount/idx/.Sent/dovecot.index.log <http://mydomain.ext/testaccount/idx/.Sent/dovecot.index.log> (seq=11, reset=yes)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Trash: Rotated transaction log /var/vmail-local/mydomain.ext/testaccount/idx/.Trash/dovecot.index.log <http://mydomain.ext/testaccount/idx/.Trash/dovecot.index.log> (seq=11, reset=yes)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Change during sync: Remote lost mailbox GUID 4b70ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Change during sync: Remote lost mailbox GUID 4d70ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Change during sync: Remote lost mailbox GUID 4c70ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Change during sync: Remote lost mailbox GUID 4a70ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: brain M: Change during sync: Remote lost mailbox GUID 4970ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Warning: Mailbox changes caused a desync. You may want to run dsync again: Remote lost mailbox GUID 4b70ba2389484d628fa91300660b22f9 (maybe it was just deleted?)
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:12:17 doveadm(testaccount at mydomain.ext)<38324><WJH0HGFLTWK0lQAAxdOQ8Q>: Debug: dict(file): dict destroyed
2022-04-06 10:12:17 doveadm(38324): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb (pid=181,uid=0): Disconnected: Connection closed (fd=9)
------------------------- CUT -------------------------------------
Here's the sync with merge:
------------------- CUT ----------------------------------
# doveadm -v sync -1df -u 'testaccount at mydomain.ext'
Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm
2022-04-06 10:13:25 Debug: Loading modules from directory: /usr/lib/dovecot/modules
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/lib02_lazy_expunge_plugin.so
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so
2022-04-06 10:13:25 Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so
2022-04-06 10:13:25 Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): Started passdb lookup
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb: Connecting
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb (pid=181,uid=0): Client connected (fd=9)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): auth PASS input: user=testaccount at mydomain.ext
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: auth-master: passdb lookup(testaccount at mydomain.ext): Finished passdb lookup (user=testaccount at mydomain.ext )
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): Started userdb lookup
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): auth USER input: testaccount at mydomain.ext home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount> mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx> uid=5000 gid=5000 quota_rule=*:storage=0B sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: auth-master: userdb lookup(testaccount at mydomain.ext): Finished userdb lookup (username=testaccount at mydomain.ext home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount> mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx> uid=5000 gid=5000 quota_rule=*:storage=0B sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: Added userdb setting: mail=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: Added userdb setting: plugin/quota_rule=*:storage=0B
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><>: Debug: Added userdb setting: plugin/sieve=/var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Effective uid=5000, gid=5000, home=/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl: No acl_shared_dict setting - shared mailbox listing is disabled
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Quota root: name=user backend=dict args=:file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Quota rule: root=user mailbox=* bytes=0 messages=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Quota rule: root=user mailbox=EXPUNGED ignored
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Quota grace: root=user bytes=0 (10%)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: quota-dict: user=testaccount at mydomain.ext, uri=file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>, noenforcing=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): dict created (uri=file:/var/vmail/mydomain.ext/testaccount/.quotausage <http://mydomain.ext/testaccount/.quotausage>, base_dir=/var/run/dovecot)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: maildir++: root=/var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>, index=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/idx>, indexpvt=, control=, inbox=/var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>, alt=
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot.acl
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl: acl username = testaccount at mydomain.ext
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl: owner = 1
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot.acl
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: brain M: Namespace has location maildir:/var/vmail/mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx <http://mydomain.ext/testaccount/Maildir:INDEX=/var/vmail-local/mydomain.ext/testaccount/idx>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'INBOX' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/dovecot-acl <http://mydomain.ext/testaccount/Maildir/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox '' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Trash' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Sent' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Junk' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox 'Drafts' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext): Debug: Namespace : Using permissions from /var/vmail/mydomain.ext/testaccount/Maildir <http://mydomain.ext/testaccount/Maildir>: mode=0700 gid=default
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Local mailbox tree: INBOX guid=4d70ba2389484d628fa91300660b22f9 uid_validity=1649232013 uid_next=2 subs=no last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Drafts guid=4b70ba2389484d628fa91300660b22f9 uid_validity=1649232011 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Junk guid=4c70ba2389484d628fa91300660b22f9 uid_validity=1649232012 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Sent guid=4a70ba2389484d628fa91300660b22f9 uid_validity=1649232010 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Local mailbox tree: Trash guid=4970ba2389484d628fa91300660b22f9 uid_validity=1649232009 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: INBOX guid=08b6a62792484d624b890000c5d390f1 uid_validity=1649232018 uid_next=1 subs=no last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Junk guid=6afcbb2f92484d624b890000c5d390f1 uid_validity=1649232021 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Drafts guid=6bfcbb2f92484d624b890000c5d390f1 uid_validity=1649232022 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Sent guid=69fcbb2f92484d624b890000c5d390f1 uid_validity=1649232020 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Remote mailbox tree: Trash guid=68fcbb2f92484d624b890000c5d390f1 uid_validity=1649232019 uid_next=1 subs=yes last_change=0 last_subs=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Mailbox Drafts: local=4b70ba2389484d628fa91300660b22f9/0/1, remote=6bfcbb2f92484d624b890000c5d390f1/0/1: GUIDs conflict - will be merged later
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Mailbox INBOX: local=4d70ba2389484d628fa91300660b22f9/0/1, remote=08b6a62792484d624b890000c5d390f1/0/1: GUIDs conflict - will be merged later
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Mailbox Junk: local=4c70ba2389484d628fa91300660b22f9/0/1, remote=6afcbb2f92484d624b890000c5d390f1/0/1: GUIDs conflict - will be merged later
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Mailbox Sent: local=4a70ba2389484d628fa91300660b22f9/0/1, remote=69fcbb2f92484d624b890000c5d390f1/0/1: GUIDs conflict - will be merged later
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: brain M: Mailbox Trash: local=4970ba2389484d628fa91300660b22f9/0/1, remote=68fcbb2f92484d624b890000c5d390f1/0/1: GUIDs conflict - will be merged later
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox Drafts: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox 'Drafts' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Drafts/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: doveadm-sieve: Iterating Sieve mailbox attributes
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: Pigeonhole version 0.5.18 (0bc28b32) initializing
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: include: sieve_global is not set; it is currently not possible to include `:global' scripts.
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Performing auto-detection
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Use home (/var/vmail/mydomain.ext/testaccount <http://mydomain.ext/testaccount>)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Using active Sieve script path: /var/vmail/mydomain.ext/testaccount/.sieve <http://mydomain.ext/testaccount/.sieve>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Using script storage path: /var/vmail/mydomain.ext/testaccount/sieve <http://mydomain.ext/testaccount/sieve>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Using permissions from /var/vmail/mydomain.ext/testaccount/sieve <http://mydomain.ext/testaccount/sieve>: mode=0700 gid=-1
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Created storage directory /var/vmail/mydomain.ext/testaccount/sieve/tmp <http://mydomain.ext/testaccount/sieve/tmp>
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: Relative path to sieve storage in active link: sieve/
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: sieve: file storage: sync: Synchronization active
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox 'INBOX' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/dovecot-acl <http://mydomain.ext/testaccount/Maildir/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: UID 1: Opened mail because: prefetch
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: Adding field date.received to cache for the first time (uid=1)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: Adding field date.save to cache for the first time (uid=1)
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: Purging (new file_seq=1649232805): creating cache
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox INBOX: Purging finished, file_seq changed 1649232018 -> 1649232805, size=676 -> 172, max_uid=0
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox Junk: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox 'Junk' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Junk/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox Sent: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox 'Sent' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Sent/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox Trash: Mailbox opened
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: Mailbox 'Trash' matches global ACL pattern '*'
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: acl vfile: file /var/vmail/mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl <http://mydomain.ext/testaccount/Maildir/.Trash/dovecot-acl> not found
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): Waiting for dict to finish pending operations
2022-04-06 10:13:25 doveadm(testaccount at mydomain.ext)<38465><+7naC6VLTWJBlgAAxdOQ8Q>: Debug: dict(file): dict destroyed
2022-04-06 10:13:25 doveadm(38465): Debug: auth-master: conn unix:/var/run/dovecot/auth-userdb (pid=181,uid=0): Disconnected: Connection closed (fd=9)
------------------------ CUT --------------------------------------
More information about the dovecot
mailing list