CORRECT PATCH Re: sync_client bails when encountering a deleted message

Ken Murchison murch at andrew.cmu.edu
Tue May 15 09:52:25 EDT 2007


Obviously, the chances of header_size being 0xdeadbeef is remote, but it 
is possible.  Would it make more sense to use ULONG_MAX as the "failure 
size"?


John Capo wrote:
> Grrr, bad cut-and-paste.  Correct patches attached.
> 
> Quoting John Capo (jc at irbs.com):
>> These patches handle the message deleted case and the folder rename
>> case properly.  Should handle all cases of messages and folders
>> disappearing while working on a folder.  May handle deleting a user
>> while working on that user.
>>
>> John Capo
>>
>>
>>
>> Quoting John Capo (jc at irbs.com):
>>> 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
>>>
>>>
>>>
> 
>> diff -ru cyrus-imapd-2.3.7/imap/sync_client.c cyrus-imapd-2.3.7-abort-upload/imap/sync_client.c
>> --- cyrus-imapd-2.3.7/imap/sync_client.c	Sun May 13 11:56:58 2007
>> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_client.c	Sun May 13 12:06:27 2007
>> @@ -1179,6 +1179,9 @@
>>          if (r) {
>>              syslog(LOG_ERR, "IOERROR: opening message file %lu of %s: %m",
>>                     record->uid, mailbox->name);
>> +	    prot_printf(toserver, " %lu ", 0xdeadbeef);
>> +	    prot_flush(toserver);
>> +	    sync_msgid_remove(msgid_onserver, &record->uuid);
>>              return(IMAP_IOERROR);
>>          }
>>  
>> diff -ru cyrus-imapd-2.3.7/imap/sync_server.c cyrus-imapd-2.3.7-abort-upload/imap/sync_server.c
>> --- cyrus-imapd-2.3.7/imap/sync_server.c	Sun May 13 11:56:58 2007
>> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_server.c	Sun May 13 12:05:41 2007
>> @@ -1780,6 +1780,8 @@
>>      upload_list = sync_upload_list_create(new_last_uid, mailbox->flagname);
>>  
>>      do {
>> +	unsigned long hdr_size;
>> +
>>          err  = NULL;
>>          item = sync_upload_list_add(upload_list);
>>  
>> @@ -1870,19 +1872,28 @@
>>                  goto parse_err;
>>              }
>>  
>> -            message = sync_message_add(message_list, &item->uuid);
>> -
>>              /* Parse Message (header size, content lines, cache, message body */
>>              if ((c = getastring(sync_in, sync_out, &arg)) != ' ') {
>>                  err = "Invalid Header Size";
>>                  goto parse_err;
>>              }
>> -            message->hdr_size = sync_atoul(arg.s);
>>              
>>              if ((c = getastring(sync_in, sync_out, &arg)) != ' ') {
>>                  err = "Invalid Content Lines";
>>                  goto parse_err;
>>              }
>> +
>> +	    if ((hdr_size = sync_atoul(arg.s)) == 0xdeadbeef)
>> +	    {
>> +		/* Make sure cache data flushed to disk before we commit */
>> +		sync_message_fsync(message_list);
>> +		sync_message_list_cache_flush(message_list);
>> +		sync_upload_list_free(&upload_list);
>> +		syslog(LOG_ERR, "IOERROR: UPLOAD ABORT");
>> +		return;
>> +	    }
>> +            message = sync_message_add(message_list, &item->uuid);
>> +            message->hdr_size = sync_atoul(arg.s);
>>              message->content_lines = sync_atoul(arg.s);
>>              
>>              if ((r=sync_getcache(sync_in, sync_out, message_list, message)) != 0) {
>> diff -ru cyrus-imapd-2.3.7/imap/sync_support.c cyrus-imapd-2.3.7-abort-upload/imap/sync_support.c
>> --- cyrus-imapd-2.3.7/imap/sync_support.c	Sun May 13 11:56:59 2007
>> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_support.c	Sun May 13 12:03:25 2007
>> @@ -544,6 +544,25 @@
>>      return(NULL);
>>  }
>>  
>> +struct sync_msgid *sync_msgid_remove(struct sync_msgid_list *l,
>> +				     struct message_uuid *uuid)
>> +{
>> +    int offset = message_uuid_hash(uuid, l->hash_size);
>> +    struct sync_msgid *msgid;
>> +
>> +    if (message_uuid_isnull(uuid))
>> +        return(NULL);
>> +
>> +    for (msgid = l->hash[offset] ; msgid ; msgid = msgid->hash_next) {
>> +        if (message_uuid_compare(&msgid->uuid, uuid))
>> +	{
>> +	    msgid->uuid.value[0] = 0;
>> +	    return;
>> +	}
>> +    }
>> +    return(NULL);
>> +}
>> +
>>  /* ====================================================================== */
>>  
>>  struct sync_folder_list *sync_folder_list_create(void)
>> diff -ru cyrus-imapd-2.3.7/imap/sync_support.h cyrus-imapd-2.3.7-abort-upload/imap/sync_support.h
>> --- cyrus-imapd-2.3.7/imap/sync_support.h	Sun May 13 11:56:59 2007
>> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_support.h	Sun May 13 12:11:21 2007
>> @@ -143,6 +143,9 @@
>>  struct sync_msgid *sync_msgid_add(struct sync_msgid_list *list,
>>  				  struct message_uuid *uuid);
>>  
>> +struct sync_msgid *sync_msgid_remove(struct sync_msgid_list *list,
>> +				  struct message_uuid *uuid);
>> +
>>  struct sync_msgid *sync_msgid_lookup(struct sync_msgid_list *list,
>>  				     struct message_uuid *uuid);
>>  
> 
> 
> ------------------------------------------------------------------------
> 
> diff -ru cyrus-imapd-2.3.7/imap/sync_client.c cyrus-imapd-2.3.7-abort-upload/imap/sync_client.c
> --- cyrus-imapd-2.3.7/imap/sync_client.c	Sun May 13 11:56:58 2007
> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_client.c	Sun May 13 12:06:27 2007
> @@ -1179,6 +1179,9 @@
>          if (r) {
>              syslog(LOG_ERR, "IOERROR: opening message file %lu of %s: %m",
>                     record->uid, mailbox->name);
> +	    prot_printf(toserver, " %lu ", 0xdeadbeef);
> +	    prot_flush(toserver);
> +	    sync_msgid_remove(msgid_onserver, &record->uuid);
>              return(IMAP_IOERROR);
>          }
>  
> diff -ru cyrus-imapd-2.3.7/imap/sync_server.c cyrus-imapd-2.3.7-abort-upload/imap/sync_server.c
> --- cyrus-imapd-2.3.7/imap/sync_server.c	Sun May 13 11:56:58 2007
> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_server.c	Sun May 13 12:33:04 2007
> @@ -1780,6 +1780,8 @@
>      upload_list = sync_upload_list_create(new_last_uid, mailbox->flagname);
>  
>      do {
> +	unsigned long hdr_size;
> +
>          err  = NULL;
>          item = sync_upload_list_add(upload_list);
>  
> @@ -1870,15 +1872,24 @@
>                  goto parse_err;
>              }
>  
> -            message = sync_message_add(message_list, &item->uuid);
> -
>              /* Parse Message (header size, content lines, cache, message body */
>              if ((c = getastring(sync_in, sync_out, &arg)) != ' ') {
>                  err = "Invalid Header Size";
>                  goto parse_err;
>              }
> -            message->hdr_size = sync_atoul(arg.s);
>              
> +	    if ((hdr_size = sync_atoul(arg.s)) == 0xdeadbeef)
> +	    {
> +		/* Make sure cache data flushed to disk before we commit */
> +		sync_message_fsync(message_list);
> +		sync_message_list_cache_flush(message_list);
> +		sync_upload_list_free(&upload_list);
> +		syslog(LOG_ERR, "IOERROR: UPLOAD ABORT");
> +		return;
> +	    }
> +            message = sync_message_add(message_list, &item->uuid);
> +            message->hdr_size = sync_atoul(arg.s);
> +
>              if ((c = getastring(sync_in, sync_out, &arg)) != ' ') {
>                  err = "Invalid Content Lines";
>                  goto parse_err;
> diff -ru cyrus-imapd-2.3.7/imap/sync_support.c cyrus-imapd-2.3.7-abort-upload/imap/sync_support.c
> --- cyrus-imapd-2.3.7/imap/sync_support.c	Sun May 13 11:56:59 2007
> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_support.c	Sun May 13 12:03:25 2007
> @@ -544,6 +544,25 @@
>      return(NULL);
>  }
>  
> +struct sync_msgid *sync_msgid_remove(struct sync_msgid_list *l,
> +				     struct message_uuid *uuid)
> +{
> +    int offset = message_uuid_hash(uuid, l->hash_size);
> +    struct sync_msgid *msgid;
> +
> +    if (message_uuid_isnull(uuid))
> +        return(NULL);
> +
> +    for (msgid = l->hash[offset] ; msgid ; msgid = msgid->hash_next) {
> +        if (message_uuid_compare(&msgid->uuid, uuid))
> +	{
> +	    msgid->uuid.value[0] = 0;
> +	    return;
> +	}
> +    }
> +    return(NULL);
> +}
> +
>  /* ====================================================================== */
>  
>  struct sync_folder_list *sync_folder_list_create(void)
> diff -ru cyrus-imapd-2.3.7/imap/sync_support.h cyrus-imapd-2.3.7-abort-upload/imap/sync_support.h
> --- cyrus-imapd-2.3.7/imap/sync_support.h	Sun May 13 11:56:59 2007
> +++ cyrus-imapd-2.3.7-abort-upload/imap/sync_support.h	Sun May 13 12:11:21 2007
> @@ -143,6 +143,9 @@
>  struct sync_msgid *sync_msgid_add(struct sync_msgid_list *list,
>  				  struct message_uuid *uuid);
>  
> +struct sync_msgid *sync_msgid_remove(struct sync_msgid_list *list,
> +				  struct message_uuid *uuid);
> +
>  struct sync_msgid *sync_msgid_lookup(struct sync_msgid_list *list,
>  				     struct message_uuid *uuid);
>  


-- 
Kenneth Murchison
Systems Programmer
Project Cyrus Developer/Maintainer
Carnegie Mellon University


More information about the Cyrus-devel mailing list