sync_client bails when encountering a deleted message

[John Capo]

Pages in the middle of the night the last few days prompted me to
look into this long standing problem.

upload_message_work() returns IMAP_IOERROR when it can't map the
message being uploaded due to a race between reading the index and
actually doing the upload work.  upload_message_work() returns with
these items in the stream to the server.

 PARSED msgid uid internaldate sent-date last-updated modseq flags

The server is expecting the header_size to arrive next but most
anything can arrive depending on what client work is left to do.

Partially sanitized and shortened log entries for a case where a
folder was renamed with other operations on the same mailbox and
other mailboxes in the work queue.

03:25:01 sync_client: DELSUB gersham_domain1^com user.gersham_domain1^com.mova
03:25:01 sync_client: MAILBOX user.gersham_domain1^com
03:25:01 sync_client: MAILBOX user.gersham_domain1^com.mova
03:25:01 sync_client: MAILBOX user.gersham_domain1^com.something.mova
03:25:01 sync_client: MAILBOX user.1040001_1051001-domain2^com
03:25:01 sync_client: MAILBOX user.gersham_domain1^com.something
03:25:01 sync_client: MAILBOX user.gersham_domain1^com.Trash
03:25:01 sync_client: MAILBOX user.rismi_domain3^co^id
03:25:01 imap: Rename: gersham_domain1^com something/mova => mova
03:25:01 sync_client: IOERROR: opening message file 594 of user.gersham_domain1^com.something.mova: No such file or directory
03:25:01 sync_client:   Promoting: MAILBOX user.gersham_domain1^com.mova -> USER gersham_domain1^com
03:25:01 imap: Deleted mailbox user.gersham_domain1^com.something.mova
03:25:03 sync_client: MAILBOX user.gersham_domain1^com.something.mova
03:25:03 sync_client: MAILBOX user.1040001_1051001-domain2^com
03:25:03 sync_client: MAILBOX user.gersham_domain1^com.something
03:25:03 sync_client: MAILBOX user.gersham_domain1^com.Trash
03:25:03 sync_client: MAILBOX user.rismi_domain3^co^id
03:25:03 sync_client: MAILBOXES received BAD response: Syntax error in Append at item 3: Invalid flags
03:25:03 sync_client:   Promoting: MAILBOX user.gersham_domain1^com.something.mova -> USER gersham_domain1^com
03:25:07 sync_client: MAILBOX user.1040001_1051001-domain2^com
03:25:07 sync_client: MAILBOX user.gersham_domain1^com.something
03:25:07 sync_client: MAILBOX user.gersham_domain1^com.Trash
03:25:07 sync_client: MAILBOX user.rismi_domain3^co^id
03:25:07 sync_client: USER gersham_domain1^com
03:25:07 sync_client: UPLOAD received BAD response: Syntax error in Append at item 3: Unknown Reserved message
03:25:09 sync_client: USER gersham_domain1^com
03:25:09 sync_client: UPLOAD received BAD response: Syntax error in Append at item 3: Unknown Reserved message
03:25:13 sync_client: USER gersham_domain1^com
03:25:13 sync_client: UPLOAD received BAD response: Syntax error in Append at item 1: Unknown Reserved message
03:25:13 sync_client: Error in do_sync(): bailing out!

The failure message depends on how much work is in the queue.

sync_client: MAILBOXES: Invalid unsolicited response type 1 from server: (null)
sync_client: Discarding: 104056 010400463ca07b23db000000 ()

A few to many thousands of those depending on the mailbox size.

sync_client: MAILBOXES received BAD response: Syntax error in Append at item 3: Invalid flags

Locking the mailbox would fix it the race but it may stay locked
for longer that one would want.

I tinkered with sending a token to the server signaling it to cleanup
the message_list and the upload_list and wait for a new command but
doing that right is rather involved.

A really ugly hack is to and fake up a message and send that to
keep the stream in sync.  The fake message is deleted from the
replica on the next MAILBOX command.

    if (r) {
	char *message = "Message vanished from primary, probably deleted\r\n";

	syslog(LOG_ERR, "IOERROR: opening message file %lu of %s: %m",
	       record->uid, mailbox->name);
 
	prot_printf(toserver, " 0 0 0 {0+}\r\n");
	prot_printf(toserver, "{%lu+}\r\n", strlen(message));
	prot_write(toserver, message, strlen(message));
	mailbox_unmap_message(mailbox, record->uid, &msg_base, &msg_size);
	sequence++;    /* This variable is not used */
	return (0);
    }

Monitoring and restarting the sync_client always works but that's
ugly too.

John Capo