Re: Sync_client fails after upgrade 2.3.16 to 2.4.4

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



> As for your earlier errors...
>
> There is a bug with sync_crc calculation in 2.4.4, so I would recommend
> waiting for 2.4.5 before upgrading again.  I'm hoping we can release
> 2.4.5 very soon, and Kolab will be building their RPMs pretty quickly
> too I imagine.

Hello,

I'm hoping that this version will fix my issue with replication I posted 
to the list a few days back.  I am going to build 2.4.5 today.

What I am seeing is that replication goes bonkers at 04:02 when the 
servers replicating to each other send their logrotate messages, I start 
having CRC check issues, no mailbox found errors and everything barfs. 
Both servers are sending that inane log scan message to the same 
mailbox, whatever the root alias is.

What is most interesting is that the replication seems stuck on a 
message it sync'ed hours ago, trying to append to the existing file that 
from what I can tell is identical on both servers.  Reconstructing does 
nothing, I have to unlink manually the file in the mailbox in question, 
reconstruct, and then things start working again.

master:
Nov 29 04:02:23 node1 syncserver[2920]: Unlinking files in mailbox user.user
Nov 29 04:02:23 node1 syncserver[2920]: IOERROR: failed to parse 
/var/spool/imap/sync./2920/397912d729863f46f208e21bdfe6e71d44293f9c
Nov 29 04:02:23 node1 syncserver[2920]: Failed to append file user.user 12
Nov 29 04:02:23 node1 syncserver[2920]: Unlinking files in mailbox user.user
Nov 29 04:02:23 node1 syncserver[2920]: IOERROR: failed to parse 
/var/spool/imap/sync./2920/397912d729863f46f208e21bdfe6e71d44293f9c
Nov 29 04:02:23 node1 syncserver[2920]: Failed to append file user.user 12
Nov 29 04:02:23 node1 syncserver[2920]: Unlinking files in mailbox user.user
Nov 29 04:02:45 node1 sync_client[4111]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:02:45 node1 sync_client[4111]: CRC failure on sync for 
user.user, trying full update
Nov 29 04:02:45 node1 sync_client[4111]: FETCH received NO response: 
IMAP_MAILBOX_NONEXISTENT No Such Mailbox
Nov 29 04:02:45 node1 sync_client[2867]: process 4111 exited, signaled 
to death by 6

reconstruct, and restart;

Nov 29 04:14:25 node1 syncserver[14811]: IOERROR: failed to parse 
/var/spool/imap/sync./14811/397912d729863f46f208e21bdfe6e71d44293f9c
Nov 29 04:14:25 node1 syncserver[14811]: Failed to append file user.user 12
Nov 29 04:14:25 node1 syncserver[14811]: IOERROR: failed to parse 
/var/spool/imap/sync./14811/397912d729863f46f208e21bdfe6e71d44293f9c
Nov 29 04:14:25 node1 syncserver[14811]: Failed to append file user.user 12
Nov 29 04:16:17 node1 reconstruct[14815]: user.cconn: updating sync_crc 
F1B0079E => CD1D60AD
Nov 29 04:16:17 node1 reconstruct[14815]: user.user uid 21 found - adding
Nov 29 04:16:36 node1 sync_client[14786]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:16:36 node1 sync_client[14786]: CRC failure on sync for 
user.user, trying full update
Nov 29 04:16:36 node1 sync_client[14786]: RECORD MISMATCH WITH REPLICA: 
more recent on master
Nov 29 04:16:36 node1 sync_client[14786]: master uid:21 modseq:41 
last_updated:1291022177 internaldate:1291021330 flags:()
Nov 29 04:16:36 node1 sync_client[14786]: replica uid:21 modseq:40 
last_updated:1291021330 internaldate:1291021330 flags:()
Nov 29 04:16:36 node1 sync_client[14786]: FETCH received NO response: 
IMAP_MAILBOX_NONEXISTENT No Such Mailbox
Nov 29 04:16:36 node1 sync_client[14785]: process 14786 exited, signaled 
to death by 6
Nov 29 04:17:54 node1 reconstruct[14825]: user.user uid 21 future modseq 
44 found
Nov 29 04:17:54 node1 reconstruct[14825]: user.user: updating sync_crc 
1C12D0ED => 704AAD12




slave:
Nov 29 04:02:32 node2 lmtpunix[30017]: duplicate_check: 
<201011290902.oAT92E6B029971@xxxxxxxxxxxxxxxxxxx> user.user            0
Nov 29 04:02:32 node2 lmtpunix[30017]: Delivered: 
<201011290902.oAT92E6B029971@xxxxxxxxxxxxxxxxxxx> to mailbox: user.user
Nov 29 04:02:32 node2 lmtpunix[30017]: duplicate_mark: 
<201011290902.oAT92E6B029971@xxxxxxxxxxxxxxxxxxx> user.user 
1291021352 23
Nov 29 04:02:33 node2 lmtpunix[30017]: USAGE user user: 0.024996 sys: 
0.029995
Nov 29 04:02:33 node2 sendmail[30157]: oAT92Un4030155: 
to=<root@xxxxxxxxxxxxxxxxxxx>, delay=00:00:02, xdelay=00:00:01, 
mailer=cyrusv2, pri=120873, relay=localhost, dsn=2.0.0, stat=Sent
Nov 29 04:02:45 node2 syncserver[28463]: higher modseq on replica 
user.user - 40 < 42

reconstruct and restart;

Nov 29 04:16:04 node2 reconstruct[7875]: reconstructing user.cconn
Nov 29 04:16:04 node2 reconstruct[7875]: user.cconn: updating sync_crc 
F1B0079E => CD1D60AD
Nov 29 04:16:04 node2 reconstruct[7875]: reconstructing user.cconn.Sent
Nov 29 04:16:04 node2 reconstruct[7875]: reconstructing user.cconn.Trash
Nov 29 04:16:05 node2 reconstruct[7875]: reconstructing user.cconn2
Nov 29 04:16:05 node2 reconstruct[7875]: reconstructing user.cyrus
Nov 29 04:16:05 node2 reconstruct[7875]: reconstructing user.user
Nov 29 04:16:36 node2 syncserver[7865]: higher modseq on replica 
user.user - 41 < 43

Nov 29 04:19:07 node2 sync_client[17881]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:19:07 node2 sync_client[17881]: do_folders(): update failed: 
user.user 'Mailbox format corruption detected'
Nov 29 04:19:07 node2 sync_client[17881]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:19:07 node2 sync_client[17881]: CRC failure on sync for 
user.user, trying full update
Nov 29 04:19:07 node2 sync_client[17881]: IOERROR: opening 
/var/spool/imap/u/user/user/22.: No such file or directory
Nov 29 04:19:07 node2 sync_client[17880]: process 17881 exited, signaled 
to death by 6

reconstruct and start again;

Nov 29 04:19:20 node2 syncserver[17904]: IOERROR: failed to parse 
/var/spool/imap/sync./17904/3a4cfcd97496017d40cb8be29682920eef0da4e7
Nov 29 04:19:20 node2 syncserver[17904]: Failed to append file user.user 16
Nov 29 04:21:16 node2 sync_client[27906]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:21:17 node2 sync_client[27906]: CRC failure on sync for 
user.cconn, trying full update
Nov 29 04:21:17 node2 sync_client[27906]: MAILBOX received NO response: 
IMAP_MAILBOX_CRC Checksum Failure
Nov 29 04:21:17 node2 sync_client[27906]: CRC failure on sync for 
user.user, trying full update
Nov 29 04:21:17 node2 sync_client[27906]: FETCH received NO response: 
IMAP_MAILBOX_NONEXISTENT No Such Mailbox
Nov 29 04:21:17 node2 sync_client[27905]: process 27906 exited, signaled 
to death by 6


meanwhile on the master;

Nov 29 04:21:16 node1 syncserver[2525]: higher modseq on replica 
user.cconn - 433 < 434
Nov 29 04:21:17 node1 syncserver[2525]: higher modseq on replica 
user.user - 45 < 46
Nov 29 04:21:44 node1 sync_client[2501]: MAILBOX received NO response: 
System I/O error
Nov 29 04:21:44 node1 sync_client[2501]: do_folders(): update failed: 
user.user 'The remote Server(s) denied the operation'
Nov 29 04:21:52 node1 sync_client[2501]: MAILBOX received NO response: 
System I/O error
Nov 29 04:21:52 node1 sync_client[2501]: do_folders(): update failed: 
user.user 'The remote Server(s) denied the operation'
Nov 29 04:21:52 node1 sync_client[2501]: IOERROR: The remote Server(s) 
denied the operation
Nov 29 04:21:52 node1 sync_client[2501]: Error in do_sync(): bailing 
out! The remote Server(s) denied the operation
Nov 29 04:21:52 node1 sync_client[2501]: Processing sync log file 
/var/lib/imap/sync/log-2500 failed: The remote Server(s) denied the 
operation
Nov 29 04:21:52 node1 sync_client[2500]: process 2501 exited, status 1
Nov 29 04:23:32 node1 syncserver[12603]: higher modseq on replica 
user.user - 45 < 46
Nov 29 04:23:39 node1 sync_client[12580]: MAILBOX received NO response: 
System I/O error
Nov 29 04:23:39 node1 sync_client[12580]: do_folders(): update failed: 
user.user 'The remote Server(s) denied the operation'
Nov 29 04:23:46 node1 sync_client[12580]: MAILBOX received NO response: 
System I/O error
Nov 29 04:23:46 node1 sync_client[12580]: do_folders(): update failed: 
user.user 'The remote Server(s) denied the operation'
Nov 29 04:23:46 node1 sync_client[12580]: IOERROR: The remote Server(s) 
denied the operation
Nov 29 04:23:46 node1 sync_client[12580]: Error in do_sync(): bailing 
out! The remote Server(s) denied the operation
Nov 29 04:23:46 node1 sync_client[12580]: Processing sync log file 
/var/lib/imap/sync/log-12579 failed: The remote Server(s) denied the 
operation
Nov 29 04:35:52 node1 reconstruct[10397]: user.user uid 16 not found
Nov 29 04:36:09 node1 reconstruct[10399]: user.user: updating sync_crc 
00000000 => 482C1C6F

so my only solution was to delete the 16. file under user.user, which 
was an email that was successfully replicated at 00:15 am that same day.

So is this the same bug?

In any case, this happens every day when the logrotate emails get sent 
from master to slave and slave to master, as they are sending a 
different email to the same mailbox roughly at the same time.  Hopefully 
running 2.4.5 will avoid this?

Chris

----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/


[Index of Archives]     [Cyrus SASL]     [Squirrel Mail]     [Asterisk PBX]     [Video For Linux]     [Photo]     [Yosemite News]     [gtk]     [KDE]     [Gimp on Windows]     [Steve's Art]

  Powered by Linux