[Dovecot] dsync replication errors

[Oli Schacher]

On Thu, 31 Jan 2013 22:17:28 +0200
Timo Sirainen <tss at iki.fi> wrote:

> On Thu, 2013-01-31 at 21:51 +0200, Timo Sirainen wrote:
> > On 31.1.2013, at 19.41, Oli Schacher <dovecot at lists.wgwh.ch> wrote:
> > 
> > >>> Jan 31 17:13:11 doco1 dovecot: dsync-local(user1): Error:
> > >>> Mailbox INBOX: Remote didn't send mail
> > >>> GUID=33dabe0f11980a51200c0000960042f4 (UID=104)
> > 
> > I guess there's some bug that causes this to happen in some
> > situations.. But the reason for mail duplication should be fixed
> > by: http://hg.dovecot.org/dovecot-2.2/rev/138f1c76c0ec
> > 
> > Except that shouldn't have been necessary. doveadm-server returns
> > success before it has finished running dsync. Not sure why, need to
> > debug it further.
> 
> Fixed with a bit of a kludge:
> http://hg.dovecot.org/dovecot-2.2/rev/e9e6a95cea21
> 
> 

I can confirm that it has become significantly harder to produce errors
with the latest patches. There still seems to be a problem when changes
to both mailboxes at the same time are involved, however, today I didn't
have time to test "scientifically", i just updated to latest hg and
clicked around, so this report probably won't be of much use to
you,sorry. I'll try to make reproducible tests again next week.

I'll post the errors from my clicking session anyway, maybe it helps you
figuring out what went wrong even without knowing how to reproduce. At
least the "Operation not permitted" error below when killing the
dsync process sounds unintended?


Logoutput is from changeset 78bdcb6642c7 running on both servers.


Server 1:
Feb  1 07:12:52 doco1 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=211)
Feb  1 07:12:52 doco1 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=205)
Feb  1 07:12:52 doco1 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=208)
Feb  1 07:12:54 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Error: Mailbox INBOX: Unexpected GUID mismatch for UID=205:
7a30ff22af5b0b510f0c0000960042f4 != 8230ff22af5b0b510f0c0000960042f4
Feb  1 07:12:54 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Error: Mailbox INBOX: Remote didn't send mail
GUID=7b30ff22af5b0b510f0c0000960042f4 (UID=228)
[...]
Feb  1 07:12:55 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Error: Importing mailbox INBOX failed
Feb  1 07:12:56 doco1 dovecot: dsync-local(user1): Error:
read(vmail at 192.168.23.62) failed: EOF
Feb  1 07:12:56 doco1 dovecot: dsync-local(user1): Error:
read(vmail at 192.168.23.62) failed: Broken pipe
Feb  1 07:12:56 doco1 dovecot: dsync-local(user1): Error: Remote
command returned error 75
[...]
Feb  1 07:12:57 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Error: Mailbox INBOX: Unexpected GUID mismatch for UID=291:
7b30ff22af5b0b510f0c0000960042f4 != 8d30ff22af5b0b510f0c0000960042f4
Feb  1 07:12:57 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Panic: file dsync-mailbox-import.c: line 1112
(dsync_mailbox_import_change): assertion failed: (change->type == DSYNC_MAIL_CHANGE_TYPE_SAVE)
Feb  1 07:12:57 doco1 dovecot: doveadm: Error: dsync-remote(user1):
Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0x5d4ea) 
[0x7f19cf5954ea]
-> /usr/lib64/dovecot/libdovecot.so.0(default_fatal_handler+0x32) 
[0x7f19cf5955d2] -> /usr/lib64/dovecot/libdovecot.so.0(+0x1f6ca) 
[0x7f19cf5576ca] -> /usr/bin/doveadm(dsync_mailbox_import_change+0x501) 
[0x42c881] -> /usr/bin/doveadm(dsync_brain_sync_mails+0x3a2) 
[0x4290c2] -> /usr/bin/doveadm(dsync_brain_run+0x169) 
[0x425e29] -> /usr/bin/doveadm() [0x426380] -> /usr/bin/doveadm() 
[0x434aa0] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x36) 
[0x7f19cf5a4076]
-> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0xa7) 
[0x7f19cf5a5107]
-> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x28)
[0x7f19cf5a4018] -> /usr/bin/doveadm() 
[0x424134] -> /usr/bin/doveadm() 
[0x40fe4f] -> /usr/bin/doveadm() 
[0x41067d] -> /usr/bin/doveadm(doveadm_mail_try_run+0x141) 
[0x410ba1] -> /usr/bin/doveadm(main+0x3f1) 
[0x417bc1] -> /lib64/libc.so.6(__libc_start_main+0xfd) 
[0x7f19cf1c3cdd] -> /usr/bin/doveadm() [0x40f839]
Feb  1 07:12:57 doco1 dovecot: dsync-local(user1): Error:
read(vmail at 192.168.23.62) failed: EOF


Server 2:
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Unexpected GUID mismatch for UID=205:
7a30ff22af5b0b510f0c0000960042f4 != 8230ff22af5b0b510f0c0000960042f4
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7b30ff22af5b0b510f0c0000960042f4
(UID=228)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7b30ff22af5b0b510f0c0000960042f4
(UID=234)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7b30ff22af5b0b510f0c0000960042f4
(UID=238)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7c30ff22af5b0b510f0c0000960042f4
(UID=256)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7c30ff22af5b0b510f0c0000960042f4
(UID=235)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7c30ff22af5b0b510f0c0000960042f4
(UID=239)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=255)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=226)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Mailbox
INBOX: Remote didn't send mail GUID=7a30ff22af5b0b510f0c0000960042f4
(UID=237)
Feb  1 07:12:54 doco2 dovecot: dsync-local(user1): Error: Importing
mailbox INBOX failed
Feb  1 07:13:24 doco2 dovecot: dsync-local(user1): Error: Remote
command process isn't dying, killing it
Feb  1 07:13:24 doco2 dovecot: dsync-local(user1): Error: kill()
failed: Operation not permitted


-- 
message transmitted on 100% recycled electrons