On Thu, 31 Jan 2013 22:17:28 +0200 Timo Sirainen <tss@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@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@192.168.23.62) failed: EOF Feb 1 07:12:56 doco1 dovecot: dsync-local(user1): Error: read(vmail@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@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