Dear Marcus, On Tue, Feb 25, 2014 at 08:20:39PM +0100, Marcus Schopen wrote: > Am Dienstag, den 25.02.2014, 12:39 +0100 schrieb Willy Offermans: > > Dear Friends, > > > > > > On Mon, Feb 24, 2014 at 01:17:30PM +0100, Willy Offermans wrote: > > > Dear cyrus Friends, > > > > > > I'm testing the replication option of cyrus. I have rebooted the > > > ``master'' > > > several times yesterday, but for reasons __not__ related to cyrus. Today I > > > figured out that replication was not working as expected. I tried to > > > restart replication by ``service imapd restart'' on both servers. I > > > noticed > > > some action, but replication stopped once more. I found the following in > > > my > > > logs. > > > > > > A snippet from my logs: > > > > > > <snip> > > > ... > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22755 > > > modseq:38813 last_updated:1393151348 internaldate:1393144202 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22755 modseq:38809 last_updated:1393167405 internaldate:1393144202 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22756 > > > modseq:38813 last_updated:1393151348 internaldate:1393144788 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22756 modseq:38809 last_updated:1393167405 internaldate:1393144788 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22757 > > > modseq:38813 last_updated:1393151348 internaldate:1393145814 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22757 modseq:38809 last_updated:1393167405 internaldate:1393145814 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:4057 > > > modseq:38831 last_updated:1393167452 internaldate:1348384486 flags:( Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica uid:4057 > > > modseq:6809 last_updated:1348464157 internaldate:1348384486 flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22222 (75fa289b62e23664f3cc00a11254191f65e50163) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22378 > > > modseq:38842 last_updated:1393187494 internaldate:1392368284 flags:( Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22378 modseq:38160 last_updated:1392369039 internaldate:1392368284 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22742 (639836573eacee96d0a61c086b39c155e63b6dfa) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22743 > > > modseq:38813 last_updated:1393151348 internaldate:1393095204 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22743 modseq:38809 last_updated:1393167405 internaldate:1393095204 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22744 (c85e24343dd16d5fd655ac674067382572318e29) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22745 (6df887eaa626a616e19def3affe42078d57d498b) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22746 (0698384acd5a6a8a06eae3cce1d279e0057f1935) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22747 (29d274001b7040613246d44d6848087df431f716) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22748 (e1860bb01952383639b74fb02ccc9f50674a3077) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22749 (439b4c69a007cf092c005e481dfa30bc3e1c2d95) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22750 (4da4738844df0aa502b33b392dc974954c0be05f) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22751 (40b39f7b075fec8288da1a63d63e83fc11c42b50) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22752 (c8428171c53dc75194e87fa14e9e2749b6bb95d4) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22753 (19d7127f51a9f54db9dc5c5caa49d1bfbc86bb07) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22754 (c99fde22cfb9fdd85c20f24b9154059f8c2c97f7) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22755 > > > modseq:38813 last_updated:1393151348 internaldate:1393144202 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22755 modseq:38809 last_updated:1393167405 internaldate:1393144202 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22756 > > > modseq:38813 last_updated:1393151348 internaldate:1393144788 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22756 modseq:38809 last_updated:1393167405 internaldate:1393144788 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: record mismatch > > > with replica: user.username more recent on master > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: master uid:22757 > > > modseq:38813 last_updated:1393151348 internaldate:1393145814 flags:(\Seen) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCNOTICE: replica > > > uid:22757 modseq:38809 last_updated:1393167405 internaldate:1393145814 > > > flags:(Old) > > > Feb 24 13:02:20 MyClient sync_client[74031]: SYNCERROR: only exists on > > > replica user.username 22758 (6455f52ef18c488d48a3bc0feddfeff39eb7a119) > > > Feb 24 13:07:24 MyClient imaps[74049]: DENYDB_ERROR: opening > > > /var/imap/user_deny.db: cyrusdb error > > > Feb 24 13:07:24 MyClient imaps[74049]: imapd:Loading hard-coded DH > > > parameters > > > Feb 24 13:07:24 MyClient imaps[74049]: starttls: TLSv1 with cipher > > > DHE-RSA-AES128-SHA (128/128 bits new) no authentication > > > Feb 24 13:07:24 MyClient imaps[74049]: OTP unavailable because can't > > > read/write key database /etc/opiekeys: Permission denied > > > Feb 24 13:07:28 MyClient imaps[74049]: badlogin: squid.vpn.offrom.nl > > > [10.168.0.72] DIGEST-MD5 [SASL(-13): authentication failure: client > > > response doesn't match what we generated (tried bogus)] > > > Feb 24 13:07:31 MyClient imaps[74049]: login: squid.vpn.offrom.nl > > > [10.168.0.72] username plaintext+TLS User logged in > > > SESSIONID=<MyClient.offrom.nl-74049-1393243644-1> > > > Feb 24 13:07:31 MyClient imaps[74049]: OTP unavailable because can't > > > read/write key database /etc/opiekeys: Permission denied > > > Feb 24 13:07:52 MyClient imaps[74049]: Expunged 1 messages from > > > user.username > > > Feb 24 13:07:53 MyClient sync_client[74031]: Error in do_sync(): bailing > > > out! Bad protocol > > > Feb 24 13:07:53 MyClient sync_client[74031]: Processing sync log file > > > /var/imap/sync/log-74031 failed: Bad protocol > > > ... > > > </snip> > > > > > > What does it mean and how can I solve it? > > > > > > > > > > > > Has anyone a clue? Replication needs to be really reliable. Otherwise it > > makes no sense to use it. > > Hi Willy, > > I'm new in the cyrus replication world too. I use the good old Cyrus > lady for several setups over the last 13 years, but never did the step > to replication. But since two weeks I'm building up a master/slave setup > for my own mailsytem. Therefore I'm very interested in a well working > sync between master and relica slave. And you are right: a non working > sync does not make any sense at all. For me it's a kind of hot stand by > backup. I asked on the cyrus list a few days ago how to proof if master > and replica are in good sync. See Bron's answer to "replication > questions - best practice?" last week. This isn't really enterprise, but > I don't want to move to postfix and dovcot right now. Hey, let's keep in > touch and replicate experience ;) > > What does "/var/imap/sync/log-74031" file says. > > Did you try a to run a "sync_client -u" on each user on the > master server or just to the mailbox that is the problem? > > Cheers from Bielefeld + Mit freundlichen Gruessen ;) > Marcus > >
We will stay in contact. My story is quite similar to yours: I'm also using cyrus for years now and I was only using the IMAP server part. I was and am very pleased with cyrus IMAP. Now I want to make the step to replication and eventually to cyrus murder, if possible. Thank you for pointing out "/var/imap/sync/log-74031". I was not aware it was created on the client. Though the content was not very appealing: cat /var/imap/sync/log-74031: MAILBOX user.MyName MAILBOX user.MyName I do not know what to do with this info, since it is quite obvious to me. Yesterday I have restarted the imap server on the client and the service is seemingly running without any problems so far. I stress the word seemingly, since I did not check if the replication is successful and I did not do anything else than restarting the service. So if there were inconsistencies before, then I have no clue if they were resolved. To me, there should be some kind of mechanism to check if replication is successful. My idea would be to create snapshots, calculate checksums and compare client with master. If error than rebuild, else continue. Though I admit that I have no idea how to put this into code. I could stop the cyrus imap services, calculate the checksums and do the comparisons myself. However I'm not sure how to stop the services without disturbing the replication mechanism. Regarding my previous experiences, this is not trivial. Maybe someone can point out how to stop sync_client in a secure way. -- Met vriendelijke groeten, With kind regards, Mit freundlichen Gruessen, Willy ************************************* W.K. Offermans ---- Cyrus Home Page: http://www.cyrusimap.org/ List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/ To Unsubscribe: https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
