CORRECT PATCH Re: sync_client bails when encountering a deleted message

John Capo jc at irbs.com
Mon Aug 6 12:35:27 EDT 2007


Quoting John Capo (jc at irbs.com):
> Quoting David Carter (dpc22 at cam.ac.uk):
> > On Thu, 17 May 2007, Ken Murchison wrote:
> > 
> > >Here is an untested patch which SHOULD allow the client to abort the 
> > >UPLOAD, with the server successfully accepting the messages transmitted 
> > >up to the abort.
> > >
> > >Thoughts?
> > 
> > I believe that there is a problem with this patch. Sorry that its taken 
> > this long for me to look at it properly.
> > 
> > A single mailbox event can cover multiple messages, particularly if 
> > sync_client is catching up from a backlog of transactions. Imagine the 
> > second message in a sequence disappearing under sync_client's feet.
> > 
> > 1) The first message will be replicated correctly.
> > 
> > 2) The second message will be discarded, which is probably correctly.
> > 
> > 3) The third (and any subsequent) messages will also be discarded.
> > 
> > The replica will remain out of sync until the next event on that mailbox. 
> > I think that it is important for sync_client to retry immediately.
> 
> Agreed.

The attached patch to Ken's first commit for this problem will cause
the failed upload to be promoted to a MAILBOX event.  Line numbers
in the patch are off but the patch may apply.

sync_client[80859]: APPEND user.xx_xxxx^com.^AAA
sync_client[80859]: APPEND user.xx_xxxx^com.BK
sync_client[80859]: APPEND user.xx_xxxx^com.A A
sync_client[80859]: APPEND user.xx_xxxx^com.Trash
sync_client[80859]: APPEND user.xx_xxxx^com.Sent
sync_client[80859]: IOERROR: opening message file 28000 of user.xx_xxxx^com.Sent: No such file or directory
sync_client[80859]: UPLOAD received NO response: upload to user.xx_xxxx^com.Sent: ABORTED
sync_client[80859]:   Promoting: APPEND user.xx_xxxx^com.Sent -> MAILBOX user.xx_xxxx^com.Sent
sync_client[80859]: APPEND user.xx_xxxx^com.BK
sync_client[80859]: APPEND user.xx_xxxx^com.Lists.postfix
sync_client[80859]: APPEND user.xx_xxxx^com.^AAA
sync_client[80859]: APPEND user.xx_xxxx^com.A A
sync_client[80859]: APPEND user.xx_xxxx^com.Lists.inet
sync_client[80859]: SEEN xx_xxxx^com user.xx_xxxx^com.Sent
sync_client[80859]: seen_db: user xx_xxxx^com opened /var/imap/user/j/xx_xxxx^com.seen
sync_client[80859]: MAILBOX user.xx_xxxx^com.Sent


> 
> > Here is a patch against 2.3 CVS. This patch also causes the client and 
> > server to resynchronise from an incomplete UPLOAD command by throwing a 
> > syntax error at the server end. I'm uncomfortable about just dropping off 
> > part way through an UPLOAD and pretending that everything is fine.
> 
> I finally got time to test this patch and this is what I get with
> my test case for a single message disappering out from under the
> sync_client.
> 
> This particular mailbox is a testbox that gets a number of deliveries
> directly to folders from our outbound SMTP servers and inbound MX
> servers.  That's what all the APPENDs are about.
> 
> sync_client[4093]: IOERROR: opening message file 27988 of user.xx_xxxx^com.Sent: No such file or directory
> sync_client[4093]: UPLOAD received BAD response: Syntax error in Append at item 1: Invalid flags or missing message: 
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com.Sent -> MAILBOX user.xx_xxxx^com.Sent
> sync_client[4093]: APPEND user.xx_xxxx^com.^AAA
> sync_client[4093]: SELECT received  response: 
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com.^AAA -> MAILBOX user.xx_xxxx^com.^AAA
> sync_client[4093]: APPEND user.xx_xxxx^com.BK
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com.BK -> MAILBOX user.xx_xxxx^com.BK
> sync_client[4093]: APPEND user.xx_xxxx^com.A A
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com.A A -> MAILBOX user.xx_xxxx^com.A A
> sync_client[4093]: APPEND user.xx_xxxx^com.Trash
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com.Trash -> MAILBOX user.xx_xxxx^com.Trash
> sync_client[4093]: APPEND user.xx_xxxx^com
> sync_client[4093]:   Promoting: APPEND user.xx_xxxx^com -> MAILBOX user.xx_xxxx^com
> sync_client[4093]: SEEN xx_xxxx^com user.xx_xxxx^com.Sent
> sync_client[4093]: MAILBOX user.xx_xxxx^com.Sent
> sync_client[4093]: MAILBOX user.xx_xxxx^com.^AAA
> sync_client[4093]: MAILBOX user.xx_xxxx^com.BK
> sync_client[4093]: MAILBOX user.xx_xxxx^com.A A
> sync_client[4093]: MAILBOX user.xx_xxxx^com.Trash
> sync_client[4093]: MAILBOX user.xx_xxxx^com
> sync_client[4093]: SELECT received  response: 
> sync_client[4093]: CREATE received ** response: 7dcec8343f7f0817 user.xx_xxxx^com.Sent "xx_xxxx.com  lrswipkxtecda   xxxx    lrswipkxtea     " 279 87 1
> sync_client[4093]: MAILBOXES: Invalid unsolicited response type 1 from server: 010400463ca07d20b8000003
> sync_client[4093]: Discarding: 3978 01020044f07eb823c1000000 ()
> sync_client[4093]: Discarding: 3979 01020044f07eb823f4000000 ()
> 
> ....
> 
> sync_client[4093]: Discarding: 244418 010400463ca07d1743000002 ()
> sync_client[4093]: Discarding: 244575 010400463ca07d1f22000003 ()
> sync_client[4093]: Discarding: Mailboxes finished
> sync_client[4093]: sync_eatlines_unsolicited(): resynchronised okay
> sync_client[4093]: MAILBOXES received NO response: Create user.xx_xxxx^com.Sent failed: Mailbox already exists
> sync_client[4093]: UNLOCK received ** response: 080a358a44ce0fb8 user.xx_xxxx^com.^AAA "xx_xxxx.com  lrswipkxtecda   xxxx_xxxxxxxx.com       lrswi pcda    xxxx    lrswipkxtea     " 244197 1
> sync_client[4093]: Error in do_sync(): bailing out!
> 
> My simple test is adding a sleep(10) in upload_message_work() and
> logging that we are sleeping.  I cause a new message to be appended
> to the Sent folder.  When I see the sleeping log entry I delete the
> message that was just appended.
> 
> I applied this patch to my code by line by line inspection of my
> code and 2.3.8.  I can't run stock 2.3.X code unless I set up
> another sandbox server.  Maybe I can do that next week.
> 
> Maybe I'm still missing something in 2.3.8 that is not in my code
> but I sure don't see it.
> 
> 
> > -- 
> > David Carter                             Email: David.Carter at ucs.cam.ac.uk
> > University Computing Service,            Phone: (01223) 334502
> > New Museums Site, Pembroke Street,       Fax:   (01223) 334679
> > Cambridge UK. CB2 3QH.
> 
> > Index: imap/sync_client.c
> > ===================================================================
> > RCS file: /cvs/src/cyrus/imap/sync_client.c,v
> > retrieving revision 1.11
> > diff -u -r1.11 sync_client.c
> > --- imap/sync_client.c	18 May 2007 13:24:39 -0000	1.11
> > +++ imap/sync_client.c	2 Jul 2007 16:49:55 -0000
> > @@ -1132,7 +1132,6 @@
> >          prot_printf(toserver, " COPY");
> >          need_body = 0;
> >      } else {
> > -        sync_msgid_add(msgid_onserver, &record->uuid);
> >          prot_printf(toserver, " PARSED");
> >          need_body = 1;
> >      }
> > @@ -1177,9 +1176,9 @@
> >          if (r) {
> >              syslog(LOG_ERR, "IOERROR: opening message file %lu of %s: %m",
> >                     record->uid, mailbox->name);
> > -	    sync_msgid_remove(msgid_onserver, &record->uuid);
> >              return(IMAP_IOERROR);
> >          }
> > +        sync_msgid_add(msgid_onserver, &record->uuid);
> >  
> >          prot_printf(toserver, " %lu %lu %lu {%lu+}\r\n",
> >  		    record->header_size, record->content_lines,
> > @@ -1259,6 +1258,10 @@
> >      prot_printf(toserver, "\r\n"); 
> >      prot_flush(toserver);
> >  
> > +    if (r) {
> > +        sync_parse_code("UPLOAD", fromserver, SYNC_PARSE_EAT_OKLINE, NULL);
> > +        return(r);
> > +    }
> >      r = sync_parse_code("UPLOAD", fromserver, SYNC_PARSE_NOEAT_OKLINE, NULL);
> >      if (r) return(r);
> >  
> > @@ -1331,6 +1334,10 @@
> >      prot_printf(toserver, "\r\n"); 
> >      prot_flush(toserver);
> >  
> > +    if (r) {
> > +        sync_parse_code("UPLOAD", fromserver, SYNC_PARSE_EAT_OKLINE, NULL);
> > +        return(r);
> > +    }
> >      r = sync_parse_code("UPLOAD", fromserver, SYNC_PARSE_NOEAT_OKLINE, NULL);
> >      if (r) return(r);
> >  
> > Index: imap/sync_server.c
> > ===================================================================
> > RCS file: /cvs/src/cyrus/imap/sync_server.c,v
> > retrieving revision 1.6
> > diff -u -r1.6 sync_server.c
> > --- imap/sync_server.c	30 May 2007 15:04:12 -0000	1.6
> > +++ imap/sync_server.c	2 Jul 2007 16:49:55 -0000
> > @@ -1870,7 +1870,7 @@
> >          switch (msg_type) {
> >          case MSG_SIMPLE:
> >              if (c != ' ') {
> > -                err = "Invalid flags";
> > +                err = "Invalid flags or missing message";
> >                  goto parse_err;
> >              }
> >  
> > @@ -1897,9 +1897,8 @@
> >              break;
> >          case MSG_PARSED:
> >              if (c != ' ') {
> > -		/* Missing message - UPLOAD short-circuited by client */
> > -		sync_upload_list_remove(upload_list, item);
> > -		goto done;
> > +                err = "Invalid flags or missing message";
> > +                goto parse_err;
> >              }
> >  
> >              message = sync_message_add(message_list, &item->uuid);
> 
-------------- next part --------------
--- last-sync_server.c	Thu May 17 17:38:05 2007
+++ sync_server.c	Mon Aug  6 12:19:33 2007
@@ -1788,6 +1788,7 @@
     int   c;
     enum {MSG_SIMPLE, MSG_PARSED, MSG_COPY} msg_type;
     int   r = 0;
+    int abort = 0;
     char *err;
 
     *restart = 0;
@@ -1912,8 +1913,10 @@
             if (c != ' ') {
                /* Missing message - UPLOAD short-circuited by client */
                sync_upload_list_remove(upload_list, item);
+	       abort = 1;
                goto done;
             }
+
             message = sync_message_add(message_list, &item->uuid);
 
             /* Parse Message (header size, content lines, cache, message body */
@@ -1981,6 +1984,9 @@
     if (r) {
         prot_printf(sync_out, "NO Failed to commit message upload to %s: %s\r\n",
                  mailbox->name, error_message(r));
+    } else if (abort) {
+        prot_printf(sync_out, "NO upload to %s: ABORTED\r\n",
+                 mailbox->name);
     } else {
 	if ((*restart = sync_message_list_need_restart(message_list)))
 	    syslog(LOG_INFO, "UPLOAD: issuing RESTART");



More information about the Cyrus-devel mailing list