doveadm backup only working once?
All,
For the past 2 weeks I have been trying to get dovecot mail backup working between 2 debian 10 machines.
Both machines are running the same OS (Debian 10) and configuration wise they are similar (except of course ip addresses, hostnames etc).
My "main" machine is called "server" and the 2nd machine is "server2".
See below for the dovecot -n output on server2.
I created a testuser called synctest on both server1 and server2 and have sent a couple (2) email messages to synctest@server.
Those testmessages are now present in /var/mail/synctest mbox file on server1.
When trying to create a backup from server->server2 for user synctest I use this command:
#doveadm -D -v backup -R -f -u synctest tcp:192.168.3.1:12345 (using something similar from server1 -> server2 like this: #doveadm -D -v backup -f -u synctest tcp:192.168.3.2:12345 has the same results btw)
The first attempte appears to be working OK but the the 2nd attempt (nothing was changed on server1 before the 2nd attempt) fails with soemthing like: Error: Couldn't delete mailbox INBOX: Permission denied
Before I can get a succesfull backup again I need to do this (on server2):
#rm /var/mail/synctest #rm -r ~syncuser/mail/index/INBOX #doveadm mailbox delete -u synctest INBOX (if I don't do the rm /var/mail/synctest before the doveadm mailbox delete command I will also get a: Error: Can't delete mailbox INBOX: Permission denied
Anybody any idea what is happening here? Should I enable replicator and/or aggregator?
Output of 1st and 2nd dovadm backup attempt is below:
root@server2:/home/synctest/mail# doveadm -D -v backup -R -f -u synctest tcp:192.168.3.1:12345 Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm Debug: Skipping module doveadm_acl_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so: undefined symbol: acl_user_module (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_expire_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so: undefined symbol: expire_set_deinit (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_quota_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so: undefined symbol: quota_user_module (this is usually intentional, so just ignore this message) Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_sieve_plugin.so Debug: Skipping module doveadm_fts_lucene_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_lucene_plugin.so: undefined symbol: lucene_index_iter_deinit (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_fts_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_plugin.so: undefined symbol: fts_user_get_language_list (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_mail_crypt_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/libdoveadm_mail_crypt_plugin.so: undefined symbol: mail_crypt_box_get_pvt_digests (this is usually intentional, so just ignore this message) doveadm(synctest)<13039><>: Debug: auth USER input: synctest system_groups_user=synctest uid=1006 gid=100 home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): auth USER input: synctest system_groups_user=synctest uid=1006 gid=100 home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): Effective uid=1006, gid=100, home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: remote(192.168.3.1:12345): fs: root=/home/synctest/mail/mailboxes, index=/home/synctest/mail/index, indexpvt=, control=/home/synctest/mail/control, inbox=/var/mail/synctest, alt= doveadm(synctest): Debug: Effective uid=1006, gid=100, home=/home/synctest doveadm(synctest): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: fs: root=/home/synctest/mail/mailboxes, index=/home/synctest/mail/index, indexpvt=, control=/home/synctest/mail/control, inbox=/var/mail/synctest, alt= doveadm(synctest): Debug: brain M: Namespace has location mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Remote mailbox tree: INBOX guid=f8ecea204a65f05fea460000b4581695 uid_validity=1609590090 uid_next=9 subs=no last_change=0 last_subs=0 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Mailbox INBOX: local=00000000000000000000000000000000/0/0, remote=f8ecea204a65f05fea460000b4581695/0/1: mailbox not selectable yet dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=1 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=2 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=3 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=4 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=5 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=6 hdr_hash= result=Expunged mail not found locally dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Last common UID=0. Delayed expunges= dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=save GUID=8bce3bc615e7f2a1dfad970a3cd36bdb UID=7 hdr_hash= result=Mail's UID is above local UIDNEXT - No more local mails found dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import change type=save GUID=c9cdf5f725d4195db78b20bbacad189b UID=8 hdr_hash= result=New mail dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: import mail uid 0 guid 8bce3bc615e7f2a1dfad970a3cd36bdb dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import mail body for GUID=8bce3bc615e7f2a1dfad970a3cd36bdb UID=0 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: /home/synctest/mail/index/INBOX/dovecot.index.cache: Compressed, file_seq changed 0 -> 1609779677, size=32, max_uid=0 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: import mail uid 0 guid c9cdf5f725d4195db78b20bbacad189b dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Import mail body for GUID=c9cdf5f725d4195db78b20bbacad189b UID=0 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Saved UIDs: 7:8 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Finish update: min_next_uid=9 min_first_recent_uid=1 min_highest_modseq=10 min_highest_pvt_modseq=0 dsync-local(synctest)<D+AKA91J81/vMgAAaso27A>: Debug: brain M: Import INBOX: Reassign UIDs: 1:
This appears to work perfectly well the first time (maybe I am overlooking some issue already at this stage?) At least after the backup has been completed /var/mail/syncuser on server2 contains all the messages that are also present on server1. And the ~syncuser/mail/index/INBOX folder also exists (don't know why this is created btw?)
But then when running the same command for the 2nd time (and no changes on the /var/mail/synctest file on server1) the command failes like this (permission denied to delete INBOX at the end):
root@server2:/home/synctest/mail# doveadm -D -v backup -R -f -u synctest tcp:192.168.3.1:12345 Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm Debug: Skipping module doveadm_acl_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so: undefined symbol: acl_user_module (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_expire_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so: undefined symbol: expire_set_deinit (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_quota_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so: undefined symbol: quota_user_module (this is usually intentional, so just ignore this message) Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_sieve_plugin.so Debug: Skipping module doveadm_fts_lucene_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_lucene_plugin.so: undefined symbol: lucene_index_iter_deinit (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_fts_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_plugin.so: undefined symbol: fts_user_get_language_list (this is usually intentional, so just ignore this message) Debug: Skipping module doveadm_mail_crypt_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/libdoveadm_mail_crypt_plugin.so: undefined symbol: mail_crypt_box_get_pvt_digests (this is usually intentional, so just ignore this message) doveadm(synctest)<13056><>: Debug: auth USER input: synctest system_groups_user=synctest uid=1006 gid=100 home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): auth USER input: synctest system_groups_user=synctest uid=1006 gid=100 home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): Effective uid=1006, gid=100, home=/home/synctest doveadm(synctest): Debug: remote(192.168.3.1:12345): Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: remote(192.168.3.1:12345): fs: root=/home/synctest/mail/mailboxes, index=/home/synctest/mail/index, indexpvt=, control=/home/synctest/mail/control, inbox=/var/mail/synctest, alt= doveadm(synctest): Debug: Effective uid=1006, gid=100, home=/home/synctest doveadm(synctest): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: fs: root=/home/synctest/mail/mailboxes, index=/home/synctest/mail/index, indexpvt=, control=/home/synctest/mail/control, inbox=/var/mail/synctest, alt= doveadm(synctest): Debug: brain M: Namespace has location mbox:~/mail/mailboxes:INBOX=/var/mail/synctest:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control doveadm(synctest): Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions doveadm(synctest): Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Local mailbox tree: INBOX guid=f8ecea204a65f05fea460000b4581695 uid_validity=1609590090 uid_next=9 subs=no last_change=0 last_subs=0 dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Remote mailbox tree: INBOX guid=f8ecea204a65f05fea460000b4581695 uid_validity=1609590090 uid_next=9 subs=no last_change=0 last_subs=0 dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Mailbox INBOX: local=f8ecea204a65f05fea460000b4581695/0/1, remote=f8ecea204a65f05fea460000b4581695/0/1: Mailboxes are equal dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: Namespace : /home/synctest/mail/mailboxes/INBOX doesn't exist yet, using default permissions dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: Namespace : Using permissions from /home/synctest/mail/mailboxes: mode=0700 gid=default dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=1 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=2 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=3 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=4 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=5 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=expunge GUID=<unknown> UID=6 hdr_hash= result=Expunged mail has no GUID, can't verify it dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Warning: Deleting mailbox 'INBOX': UID=7 already exists locally for a different mail: Headers hashes don't match (9fc2f2229a1a2a8d5f12304cb5287f97 vs b62e0281b4f375a45040c552b55ab31a) dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Import change type=save GUID=8bce3bc615e7f2a1dfad970a3cd36bdb UID=7 hdr_hash=9fc2f2229a1a2a8d5f12304cb5287f97 result=Headers hashes don't match (9fc2f2229a1a2a8d5f12304cb5287f97 vs b62e0281b4f375a45040c552b55ab31a) dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: brain M: Import INBOX: Saved UIDs: dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: doveadm-sieve: Iterating Sieve mailbox attributes dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: Pigeonhole version 0.5.4 () initializing dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: include: sieve_global is not set; it is currently not possible to include `:global' scripts. dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: file storage: Using active Sieve script path: /home/synctest/.dovecot.sieve dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: file storage: Using script storage path: /home/synctest/sieve dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: file storage: Using permissions from /home/synctest/sieve: mode=0700 gid=-1 dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: file storage: Relative path to sieve storage in active link: sieve/ dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Debug: sieve: file storage: sync: Synchronization active dsync-local(synctest)<VqbhHQhL818AMwAAaso27A>: Error: Couldn't delete mailbox INBOX: Permission denied
root@server2:/home/synctest/mail# dovecot -n
2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf
Pigeonhole version 0.5.4 ()
OS: Linux 4.19.0-12-amd64 x86_64 Debian 10.6
Hostname: server2.fritz.box
auth_username_format = %Ln doveadm_password = # hidden, use -P to show it lda_mailbox_autocreate = yes login_trusted_networks = 192.168.3.0/24 mail_location = mbox:~/mail/mailboxes:INBOX=/var/mail/%u:DIRNAME=mBoX-MeSsAgEs:INDEX=~/mail/index:CONTROL=~/mail/control mail_privileged_group = mail managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { driver = pam } plugin { sieve = ~/.dovecot.sieve sieve_default = /var/lib/dovecot/sieve/default.sieve sieve_dir = ~/sieve } postmaster_address = postmaster@"domain" protocols = imap pop3 lmtp service doveadm { inet_listener { port = 12345 } } service managesieve-login { inet_listener sieve { port = 4190 } } ssl_cert = </etc/letsencrypt/live/"domain"/fullchain.pem ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it userdb { driver = passwd } protocol lmtp { mail_plugins = " sieve" } protocol lda { mail_plugins = " sieve" }
All,
Maybe a relevant piece of additional information that could help in figurring out what is going wrong here that I forgot to add in my previous posting.
After the succesfull first backup execution using: #doveadm -D -v backup -R -f -u synctest tcp:192.168.3.1:12345
as described in detail below the /var/mail/synctest inbox file contains this (using mail -f /var/mail/synctest):
root@mail:/var/mail# mail -f synctest Mail version 8.1.2 01/15/2001. Type ? for help. "synctest": 2 messages 2 unread
U 1 torremans@mail.to Mon Jan 04 17:56 29/1016 Testmail 1 U 2 torremans@mail.to Mon Jan 04 17:56 28/982 Testmail 2
After the 2nd backup command (same command) it contains:
root@server2:/var/mail# mail -f synctest Mail version 8.1.2 01/15/2001. Type ? for help. "synctest": 1 message
1 MAILER-DAEMON@ser Wed Jan 06 14:05 13/534 DON'T DELETE THIS MESSAGE -- FOLDER INTERNAL DATA
Looks like for some reason the inbox file is reset/recreated? Anybody any idea what could cause this behaviour? Running the doveadm backup command a 3rd of 4th time does not change the /var/mail/synctest file anymore. Also the date/time of the file is not updated anymore
Thanks,
Engelbert
Op 4-1-2021 om 18:25 schreef Engelbert Torremans:
OK. So you are suggesting that moving to mdbox could solve my problem?
I could migrate/reconfigure my "server2" to mdbox while keeping my "production/server1" running on mbox and backup everything from server1->server2 and switch over once everything proves to be working OK.
Engelbert
Op 6-1-2021 om 15:40 schreef Aki Tuomi:
I experienced some corruption with mdbox that I had to move away from it to Maildir. Anyway, that's just me,
On Wed, 6 Jan 2021 at 17:54, Engelbert Torremans <engelbert@torremans.com> wrote:
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 "Oh, the cruft.", grep ^[^#] :-)
participants (4)
-
Aki Tuomi
-
Christian Kivalo
-
Engelbert Torremans
-
Odhiambo Washington