Re: [imapsync] Issue migrating large mailboxes from FirstClass to Dovecot

[Scott Barber <sabarber at me dot com>]

OK, so the good news is that with the latest imapsync 1.321 and Mail::IMAPClient 3.25, the split/maxcommandlength stuff is working fine.

Now, I am at some point running into what seems like an issue in the reconnect logic.

Here, my connection to the server times out.  OK, so we go into reconnect...

         UID 5043093)
ERROR: timeout waiting 30s for data from server at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1852
        Mail::IMAPClient::_read_more('Mail::IMAPClient=HASH(0x10096e3a0)', 'IO::Socket::INET=GLOB(0x10096d2a8)', 30) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1642
        Mail::IMAPClient::_read_line('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1435
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2003, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093) called at /usr/local/bin/imapsync line 1743
reconnecting to xxxx.xxxx.xxx, last error: timeout waiting 30s for data from server
Connecting via IO::Socket::INET to xxxx.xxxx.xxx:143 Timeout 30
Connected to xxxx.xxxx.xxx errno(Socket is already connected)
ERROR: timeout waiting 30s for data from server: Socket is already connected at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1852
        Mail::IMAPClient::_read_more('Mail::IMAPClient=HASH(0x10096e3a0)', 'IO::Socket::INET=GLOB(0x100bf96e8)', 30) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1642
        Mail::IMAPClient::_read_line('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1435
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', '*', 'PREAUTH') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 373
        Mail::IMAPClient::Socket('Mail::IMAPClient=HASH(0x10096e3a0)', 'IO::Socket::INET=GLOB(0x100bf96e8)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 344
        Mail::IMAPClient::connect('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1294
        Mail::IMAPClient::reconnect('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1327
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093) called at /usr/local/bin/imapsync line 1743
reconnect failed on try #1

Noting that I get a "Socket is already connected" error message back.  At this point, we take another shot and an AUTHENTICATE CRAM-MD5 is sent this time:

reconnecting to xxxx.xxxx.xxx, last error: timeout waiting 30s for data from server: Socket is already connected
Connecting via IO::Socket::INET to xxxx.xxxx.xxx:143 Timeout 30
Connected to xxxx.xxxx.xxx errno(Socket is already connected)
Read:   * OK FirstClass IMAP4rev1 server v10.010 at xxxx.xxxx.xxx ready
Sending: 2004 AUTHENTICATE CRAM-MD5
Sent 28 bytes
Read:   + PDIwMTAwNzA5MjEzODE1LjIzNDE5MjA0OEBsa3NkLm9yZz4=
Sending: Y2t1aG5zIDZhMWZmYzQ2Y2EyZjkyNDZjNjQ3NjY4ODQxMTAwZjc4
Sent 54 bytes
Read:   2004 NO AUTHENTICATE failed, invalid userid or password
ERROR: 2004 NO AUTHENTICATE failed, invalid userid or password at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 3195
        Mail::IMAPClient::authenticate('Mail::IMAPClient=HASH(0x10096e3a0)', 'CRAM-MD5', undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 436
        Mail::IMAPClient::login('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 388
        Mail::IMAPClient::Socket('Mail::IMAPClient=HASH(0x10096e3a0)', 'IO::Socket::INET=GLOB(0x111307c10)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 344
        Mail::IMAPClient::connect('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1294
        Mail::IMAPClient::reconnect('Mail::IMAPClient=HASH(0x10096e3a0)') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1327
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093) called at /usr/local/bin/imapsync line 1743
reconnect failed on try #2

And now the reconnect fails -- I'm not sure why the authenticate fails, but perhaps we're not sending the userid again?

Except we just forge ahead and send the UID FETCH, which results in a BAD being thrown back to us (presumably since we are not authenticated):

Sending: 2005 UID FETCH 5043093 BODY.PEEK[]
Sent 36 bytes
Read:   2005 BAD command not understood
ERROR: 2005 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1457
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2005, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093) called at /usr/local/bin/imapsync line 1743
ERROR: timeout waiting 30s for data from server; timeout waiting 30s for data from server: Socket is already connected; 2004 NO AUTHENTICATE failed, invalid userid or password; 2005 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1357
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043093 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043093) called at /usr/local/bin/imapsync line 1743
Could not fetch message #5043093 from INBOX: timeout waiting 30s for data from server; timeout waiting 30s for data from server: Socket is already connected; 2004 NO AUTHENTICATE failed, invalid userid or password; 2005 BAD command not understood
+ key     fa7kTvoNwzYIBLO2VRETtQ #5043382
+ NO msg #5043382 [fa7kTvoNwzYIBLO2VRETtQ] in INBOX
+ Copying msg #5043382:2048 to folder INBOX

Now IMAPClient sends CAPABILITY?

Sending: 2006 CAPABILITY
Sent 17 bytes
Read:   * CAPABILITY IMAP4REV1 NAMESPACE AUTH=CRAM-MD5 UIDPLUS IDLE VOICEMESSAGES ACL ID CHILDREN
Read:   2006 OK CAPABILITY completed

But then back to FETCH?

Sending: 2007 UID FETCH 5043382 BODY.PEEK[]
Sent 36 bytes
Read:   2007 BAD command not understood
ERROR: 2007 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1457
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2007, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043382 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043382 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043382, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043382, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043382) called at /usr/local/bin/imapsync line 1743
ERROR: 2007 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1357
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043382 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043382, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043382, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043382) called at /usr/local/bin/imapsync line 1743
Could not fetch message #5043382 from INBOX: 2007 BAD command not understood
+ key     enpp2rmK4uLgVY3hgXpiUg #5043462
+ NO msg #5043462 [enpp2rmK4uLgVY3hgXpiUg] in INBOX
+ Copying msg #5043462:2048 to folder INBOX

And FETCH again and again...?

Sending: 2008 UID FETCH 5043462 BODY.PEEK[]
Sent 36 bytes
Read:   2008 BAD command not understood
ERROR: 2008 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1457
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2008, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043462 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043462 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043462, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043462, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043462) called at /usr/local/bin/imapsync line 1743
ERROR: 2008 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1357
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043462 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043462, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043462, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043462) called at /usr/local/bin/imapsync line 1743
Could not fetch message #5043462 from INBOX: 2008 BAD command not understood
+ key     WfOv5gvwMkxjdRge8jO8jQ #5043645
+ NO msg #5043645 [WfOv5gvwMkxjdRge8jO8jQ] in INBOX
+ Copying msg #5043645:3072 to folder INBOX
Sending: 2009 UID FETCH 5043645 BODY.PEEK[]
Sent 36 bytes
Read:   2009 BAD command not understood
ERROR: 2009 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1457
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2009, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043645 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043645 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043645, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043645, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043645) called at /usr/local/bin/imapsync line 1743
ERROR: 2009 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1357
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043645 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043645, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043645, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043645) called at /usr/local/bin/imapsync line 1743
Could not fetch message #5043645 from INBOX: 2009 BAD command not understood
+ key     llzv1LKGgnniltzKsLjdaQ #5043665
+ NO msg #5043665 [llzv1LKGgnniltzKsLjdaQ] in INBOX
+ Copying msg #5043665:866304 to folder INBOX
Sending: 2010 UID FETCH 5043665 BODY.PEEK[]
Sent 36 bytes
Read:   2010 BAD command not understood
ERROR: 2010 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1457
        Mail::IMAPClient::_get_response('Mail::IMAPClient=HASH(0x10096e3a0)', 2010, undef) called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1406
        Mail::IMAPClient::_imap_command_do('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043665 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1312
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043665 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043665, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043665, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043665) called at /usr/local/bin/imapsync line 1743
ERROR: 2010 BAD command not understood at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1357
        Mail::IMAPClient::_imap_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'UID FETCH 5043665 BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 1488
        Mail::IMAPClient::_imap_uid_command('Mail::IMAPClient=HASH(0x10096e3a0)', 'FETCH', 5043665, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 2107
        Mail::IMAPClient::fetch('Mail::IMAPClient=HASH(0x10096e3a0)', 5043665, 'BODY.PEEK[]') called at /Library/Perl/5.10.0/Mail/IMAPClient.pm line 731
        Mail::IMAPClient::message_string('Mail::IMAPClient=HASH(0x10096e3a0)', 5043665) called at /usr/local/bin/imapsync line 1743
Could not fetch message #5043665 from INBOX: 2010 BAD command not understood
+ key     rcUAt9BUcrUEHXYVrrx48g #5045777
+ NO msg #5045777 [rcUAt9BUcrUEHXYVrrx48g] in INBOX
+ Copying msg #5045777:2048 to folder INBOX

I'm going to try this with 2.2.9 now that the reconnect logic is presumably fixed to see if we have the same problems there, but this latest set of issues has me a bit confused.

Best,
Scott