Shared folder, COPY, OK, message nowhere to be seen

Janne Peltonen janne.peltonen at helsinki.fi
Mon Apr 25 04:29:31 EDT 2016 

Hi!

Yeah, I had tried to go through the code myself, and couldn't find how
what I observed could have happened.

Thank you for the in-depth answer and your time, I appreciate it. If I
can find a way to reproduce the behaviour, I'll get back to you. Right
now I'm ready to believe in random particles flipping a bit in RAM,
since this really is something I haven't seen in the more than 10 years
I've been administering a Cyrus system.


Best,

--Janne

On Sat, Apr 23, 2016 at 01:30:46AM +1000, Bron Gondwana wrote:
> It not only should be, I'm really sure it is.  I can't see a possible codepath that this could happen with - there's no such thing as "in core" here - 2.4.x doesn't even have the in-memory caching of cyrus.index changes.
> 
> This is from the cyrus-imapd-2.4.17 tag in git:
> 
> in imap/index.c: index_copy()
> 
>     r = append_copy(mailbox, &appendstate, copyargs.nummsg,
>                     copyargs.copymsg, nolink);
>     if (!r) {
>         r = append_commit(&appendstate, totalsize,
>                       &uidvalidity, &startuid, &num, &destmailbox);
>     }
> ...
>     if (!r) {
>         /* we log the first name to get GUID-copy magic */
>         mailbox_close(&destmailbox);
>         sync_log_mailbox_double(mailbox->name, name);
>     }
> 
> And then back in imapd.c: cmd_copy
> 
>    /* local mailbox -> local mailbox */
>     if (!r) {
>         r = index_copy(imapd_index, sequence, usinguid, mailboxname,
>                        &copyuid, !config_getswitch(IMAPOPT_SINGLEINSTANCESTORE));
>     }
> 
>     imapd_check(NULL, usinguid);
> 
>   done:
>     if (r && !(usinguid && r == IMAP_NO_NOSUCHMSG)) {
>         prot_printf(imapd_out, "%s NO %s%s\r\n", tag,
>                     (r == IMAP_MAILBOX_NONEXISTENT &&
>                      mboxlist_createmailboxcheck(mailboxname, 0, 0,
>                                                  imapd_userisadmin,
>                                                  imapd_userid, imapd_authstate,
>                                                  NULL, NULL, 0) == 0)
>                     ? "[TRYCREATE] " : "", error_message(r));
>     }
>     else if (copyuid) {
>             prot_printf(imapd_out, "%s OK [COPYUID %s] %s\r\n", tag,
>                         copyuid, error_message(IMAP_OK_COMPLETED));
>             free(copyuid);
>     }
>     else {
>         prot_printf(imapd_out, "%s OK %s\r\n", tag,
>                     error_message(IMAP_OK_COMPLETED));
>     }
> 
> ....
> 
> As you can see, we haven't send the response until we not only did an append_commit() and a mailbox_close(), we have also done an imapd_check().  There's no way that we haven't committed everything before replying with OK.
> 
> So unless the RPMs have some funky patches that change this behaviour, there's no way the messages are not fully copied before returning OK.  Either it hadn't returned OK yet, or it would never have finished.
> 
> I believe you saw something weird, but I think you are wrong about the exact failure.  I don't suppose you can reproduce it?
> 
> Bron.
> 
> 
> On Sat, Apr 23, 2016, at 01:21, Janne Peltonen wrote:
> > Hi!
> > 
> > Both. The message cannot be seen via IMAP in the destination mailbox and it
> > doesn't exist on the filesystem. 
> > 
> > But the message is clearly somewhere, probably in core: When I killed all the
> > other imapd processes that could've been accessing the same mailbox (that had
> > users who were mentioned in the acl of that mailbox), the messages I'd tried to
> > copy all both appeared on the file system (all at the same time, as confirmed
> > by calling "stat" on the message files - the Change timestamps were all the
> > same, and coincided with the time of the process kill) and could be fetched by
> > imap, too.
> > 
> > This is a replicating setup, if that makes any difference.
> > 
> > Right now, everything seems to be working, and I haven't seen this behaviour
> > earlier in the ~17 years I've been using Cyrus with shared folders in here - or
> > the 10 years I've been using replication - so I don't really know how to even
> > recreate the problem.
> > 
> > The semantics of the OK response *should* be "Message is safely written on disk
> > (so you can delete the original message)", shouldn't it?
> > 
> > 
> > --Janne
> > 
> > On Sat, Apr 23, 2016 at 12:56:15AM +1000, Bron Gondwana wrote:
> > > When you say the messages can't be seen... Do you mean they aren't on the
> > > file system, or that they aren't showing up via IMAP, or... ?
> > > 
> > > On Sat, Apr 23, 2016, at 00:48, Janne Peltonen wrote:
> > > > And Centos 5.11, Linux 2.6.18-407.el5.
> > > > 
> > > > 
> > > > --Janne
> > > > 
> > > > On Fri, Apr 22, 2016 at 05:43:11PM +0300, Janne Peltonen via Info-cyrus wrote:
> > > > > Hi!
> > > > > 
> > > > > Oh. Sorry. I thought I'd forgot something important, must be the fact it's
> > > > > Friday night.
> > > > > 
> > > > > 2.4.17 from Simon Matter's srpm. Revision 6 of said rpm.
> > > > > 
> > > > > 
> > > > > --Janne
> > > > > 
> > > > > On Fri, Apr 22, 2016 at 11:27:40PM +1000, Bron Gondwana via Info-cyrus wrote:
> > > > > > Version?
> > > > > > 
> > > > > > On Fri, Apr 22, 2016, at 21:47, Janne Peltonen via Info-cyrus wrote:
> > > > > > > Hi!
> > > > > > > 
> > > > > > > I've always thought that IMAP COPY should only say OK once the message file is
> > > > > > > safely on the disk. So that it should block, should another imapd process be
> > > > > > > holding a write lock to the folder.
> > > > > > > 
> > > > > > > Now today I experienced something very weird. There was a shared folder. If I
> > > > > > > tried to copy a message to it (speaking raw imap), I immediately got an OK. And
> > > > > > > the folder metadata reflected the change. However, the message wasn't on the
> > > > > > > disk. And wasn't retrievable using IMAP.
> > > > > > > 
> > > > > > > I tried this multiple times. Frustrated, I ended up killing the active imapd
> > > > > > > processes of all other users that had ACL rights to the folder. My messages
> > > > > > > immediately appeared on disk and were retrievable by IMAP. As if they'd been
> > > > > > > in-core of my imapd process and waiting for a chance to be flushed to disk.
> > > > > > > Even if the imapd process had returned OK, which I'd thought would've meant
> > > > > > > they'd already been written to disk.
> > > > > > > 
> > > > > > > Now, apparently, one of the users had copied mission critical messages to said
> > > > > > > folder and they had disappeared. Disappeared from the original folder and not
> > > > > > > shown up in the destination folder. Which was the reason I started
> > > > > > > investigating this.
> > > > > > > 
> > > > > > > Now, after having killed the imapd processes, I seem to have permanently
> > > > > > > deleted all the messages that might have been in-core of any of those processes
> > > > > > > (that had told their clients that the messages would've been on disk, i.e.
> > > > > > > COPY -> OK). I killed the imapd processes while thinking that 1) there could in
> > > > > > > no way be the slightest possibility that the messages hadn't been flushed to
> > > > > > > disk from the core of the imapd processes after COPY, as the imapd had answered
> > > > > > > OK to the client's COPY command, SO 2) one of the other users' clients must
> > > > > > > have had a rule that immediately moves the messages away. But apparently, this
> > > > > > > wasn't the case.
> > > > > > > 
> > > > > > > Has anyone else encountered something like this?
> > > > > > > 
> > > > > > > 
> > > > > > > --Janne Peltonen
> > > > > > > ----
> > > > > > > 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
> > > > > > 
> > > > > > 
> > > > > > -- 
> > > > > >   Bron Gondwana
> > > > > >   brong at fastmail.fm
> > > > > > ----
> > > > > > 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
> > > > > ----
> > > > > 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
> > > 
> > > 
> > > -- 
> > >   Bron Gondwana
> > >   brong at fastmail.fm
> 
> 
> -- 
>   Bron Gondwana
>   brong at fastmail.fm

-- 
Janne Peltonen <janne.peltonen at helsinki.fi> PGP Key ID: 0x9CFAC88B
Helsingin yliopisto / Tietotekniikkakeskus

More information about the Info-cyrus mailing list