inotify polling in master branch

[Kevin J. McCarthy]

Just a heads up that inotify polling was committed to master earlier
this week.

There _are_ still a few quirks with it that I'm looking into.
Specifically weird behavior with Esc-prefixed commands. I won't have
time to debug that until this weekend though.

If you notice other issues, please let me know.

Thank you.

[Vincent Lefevre]

Post by Kevin J. McCarthy
Just a heads up that inotify polling was committed to master earlier
this week.
There _are_ still a few quirks with it that I'm looking into.
Specifically weird behavior with Esc-prefixed commands. I won't have
time to debug that until this weekend though.
If you notice other issues, please let me know.

I've just tried it, and there is a major regression: it now fails to
detect new mail at all in the current mailbox, even when moving the
cursor, viewing messages, modifying the mailbox and synchronizing!

I'm using the Maildir format.

[Derek Martin]

Post by Vincent Lefevre

Post by Kevin J. McCarthy
Just a heads up that inotify polling was committed to master earlier
this week.
There _are_ still a few quirks with it that I'm looking into.
Specifically weird behavior with Esc-prefixed commands. I won't have
time to debug that until this weekend though.
If you notice other issues, please let me know.

I've just tried it, and there is a major regression: it now fails to
detect new mail at all in the current mailbox, even when moving the
cursor, viewing messages, modifying the mailbox and synchronizing!
I'm using the Maildir format.

I haven't looked at the patch, but I have been meaning to point out
that inotify can miss events, under system load (I think it's mostly
kernel memory pressure, but exactly how is probably irrelevant). So
if Mutt will include such a feature, it would probably be prudent to
not rely on it solely.

I'm a big fan though, I've been meaning to suggest something like this
for a while. Main reason I haven't is due to the platform-
specificness of inotify, and lack of familiarity with of alternatives
on other platforms. I would have preferred using a library that
handles that for you (the way libevent does for event-based I/O) if
there were such a thing... But I'm not aware of such a beast.

[Kevin J. McCarthy]

Post by Derek Martin

Post by Vincent Lefevre

Post by Kevin J. McCarthy
Just a heads up that inotify polling was committed to master earlier
this week.
There _are_ still a few quirks with it that I'm looking into.
Specifically weird behavior with Esc-prefixed commands. I won't have
time to debug that until this weekend though.
If you notice other issues, please let me know.

I've just tried it, and there is a major regression: it now fails to
detect new mail at all in the current mailbox, even when moving the
cursor, viewing messages, modifying the mailbox and synchronizing!
I'm using the Maildir format.

Vincent, so far I can't duplicate this. I'm a bit surprised, because
the mail detection code itself wasn't changed. inotify is watching the
maildir and returns a "timeout" event - but Mutt still has uses
$timeout and $mail_check normally.

Can you double check the change in behavior by switching between stable
and master again?

Post by Derek Martin
I haven't looked at the patch, but I have been meaning to point out
that inotify can miss events, under system load (I think it's mostly
kernel memory pressure, but exactly how is probably irrelevant). So
if Mutt will include such a feature, it would probably be prudent to
not rely on it solely.

Yes, this is an addition. In fact, $mail_check is still consulted, and
if you have it set to a large value "mailboxes" will won't be noticed
much faster.

[Kevin J. McCarthy]

Post by Vincent Lefevre
I've just tried it, and there is a major regression: it now fails to
detect new mail at all in the current mailbox, even when moving the
cursor, viewing messages, modifying the mailbox and synchronizing!
I'm using the Maildir format.

Actually, I just realized there _is_ a race condition in the maildir/mh
code I've been meaning to look into. Once in a blue moon, I've noticed
Mutt didn't notice a new mail in the currently open mailbox.

I've had it on my todo list, but hadn't had a chance to look into it
yet. Taking a quick peek, the mh_sync_mailbox() code touches the
context->mtime value using maildir_update_mtime(), and even has a
comment about a possible race condition. I'm not sure what to do about
it yet, but perhaps this is what you encountered?

[Vincent Lefevre]

Post by Kevin J. McCarthy
I've had it on my todo list, but hadn't had a chance to look into it
yet. Taking a quick peek, the mh_sync_mailbox() code touches the
context->mtime value using maildir_update_mtime(), and even has a
comment about a possible race condition. I'm not sure what to do about
it yet, but perhaps this is what you encountered?

I'm not sure I understand. If you mean that in some rare occasions,
new mail could fail to be detected, then this is a known issue I had
already seen and reported (bug 3475 in the old BTS), but I had found
that the race condition seemed to be here:

The problem occurred once again! I've looked at the code in
maildir_check_mailbox from mh.c and it seems incorrect:
{{{
/* determine which subdirectories need to be scanned */
if (st_new.st_mtime > ctx->mtime)
changed = 1;
if (st_cur.st_mtime > data->mtime_cur)
changed |= 2;

if (!changed)
return 0; /* nothing to do */

/* update the modification times on the mailbox */
data->mtime_cur = st_cur.st_mtime;
ctx->mtime = st_new.st_mtime;
}}}
This seems to be subject to race condition, in particular if new mail
arrives at about the same time the mailbox is synchronized (I think this
is what happens in my case). I don't think it is possible to avoid a race
condition when considering only the timestamp of the new subdirectory. But
for instance, a full check (scan) of the new subdirectory could be done
systematically several seconds after the latest change (due to
synchronization or new mail). I don't think it is useful to do the same
thing for the cur subdirectory.

But note that after some change and synchronizing the mailbox, the
new mail could be detected, IIRC.

Here, with inotify support enabled, this is different as new mail
is never detected. The problem disappeared when I recompiled with
--disable-filemonitor.

Now I'm thinking that there may be a more important new race condition
due to inotify because files could be looked as soon as they appear,
and if there is an mtime correction (which occurs here, AFAIK, as I'm
using unison to retrieve mail and synchronize between various copies
of my mailboxes), this might confuse Mutt.

[Kevin J. McCarthy]

Post by Vincent Lefevre

Post by Kevin J. McCarthy
I've had it on my todo list, but hadn't had a chance to look into it
yet. Taking a quick peek, the mh_sync_mailbox() code touches the
context->mtime value using maildir_update_mtime(), and even has a
comment about a possible race condition. I'm not sure what to do about
it yet, but perhaps this is what you encountered?

I'm not sure I understand. If you mean that in some rare occasions,
new mail could fail to be detected, then this is a known issue I had
already seen and reported (bug 3475 in the old BTS), but I had found

Yes, I believe we are talking about the same thing. New mail arriving
in the middle of a sync may not be noticed.

Post by Vincent Lefevre
Now I'm thinking that there may be a more important new race condition
due to inotify because files could be looked as soon as they appear,
and if there is an mtime correction (which occurs here, AFAIK, as I'm
using unison to retrieve mail and synchronize between various copies
of my mailboxes), this might confuse Mutt.

This sounds plausible. If mx_check_mailbox() is run immediately, it may
record the st_mtime before it is reset by unison.

What if instead, we changed the code from a ">" comparison to a "!="
comparison. This would force a rescan if the mtime were reset backwards:

/* determine which subdirectories need to be scanned */
if (st_new.st_mtime != ctx->mtime)
changed = 1;
if (st_cur.st_mtime != data->mtime_cur)
changed |= 2;

[Vincent Lefevre]

Post by Kevin J. McCarthy

Post by Vincent Lefevre
Now I'm thinking that there may be a more important new race condition
due to inotify because files could be looked as soon as they appear,
and if there is an mtime correction (which occurs here, AFAIK, as I'm
using unison to retrieve mail and synchronize between various copies
of my mailboxes), this might confuse Mutt.

This sounds plausible. If mx_check_mailbox() is run immediately, it may
record the st_mtime before it is reset by unison.
What if instead, we changed the code from a ">" comparison to a "!="
/* determine which subdirectories need to be scanned */
if (st_new.st_mtime != ctx->mtime)
changed = 1;
if (st_cur.st_mtime != data->mtime_cur)
changed |= 2;

I'll have to try. But I'm wondering why there is no rescan after one
does a sync-mailbox with actual changes: in any case, this may be
necessary as new mail could arrive during this time.

[Kevin J. McCarthy]

Post by Vincent Lefevre

Post by Kevin J. McCarthy
What if instead, we changed the code from a ">" comparison to a "!="

I'll have to try. But I'm wondering why there is no rescan after one
does a sync-mailbox with actual changes: in any case, this may be
necessary as new mail could arrive during this time.

So, in effect, remove the call to maildir_update_mtime() at the end of
mh_sync_mailbox()?

[Vincent Lefevre]

Post by Kevin J. McCarthy

Post by Vincent Lefevre

Post by Kevin J. McCarthy
What if instead, we changed the code from a ">" comparison to a "!="

I'll have to try. But I'm wondering why there is no rescan after one
does a sync-mailbox with actual changes: in any case, this may be
necessary as new mail could arrive during this time.

So, in effect, remove the call to maildir_update_mtime() at the end of
mh_sync_mailbox()?

I've tried again without any change and with debugging support, on
a different machine.I did a first unison. 2 new messages should have
appeared, but debugging showed "mh.c:835: queueing ..." messages,
then "mh.c:880 maildir_add_to_context(): Considering ..." messages.
without these new messages, which did not appear in the mailbox.

I did a second unison. These 2 new messages appeared, but not a newer
one that should have appeared.

I think that there is a race condition with the inotify code: the
inotify event is obtained while the mailbox hasn't been completely
updated, so that one doesn't get the latest messages. What might
happen is that the directory is being updated during the readdir.

Together with other race conditions, things may be worse than what
I'm seeing here.

[Vincent Lefevre]

Post by Vincent Lefevre

Post by Kevin J. McCarthy

Post by Vincent Lefevre

Post by Kevin J. McCarthy
What if instead, we changed the code from a ">" comparison to
a "!=" comparison. This would force a rescan if the mtime were

This doesn't have any effect.

Post by Vincent Lefevre

Post by Kevin J. McCarthy

Post by Vincent Lefevre
I'll have to try. But I'm wondering why there is no rescan after one
does a sync-mailbox with actual changes: in any case, this may be
necessary as new mail could arrive during this time.

So, in effect, remove the call to maildir_update_mtime() at the end of
mh_sync_mailbox()?

This doesn't have any effect either.

Post by Vincent Lefevre
I think that there is a race condition with the inotify code: the
inotify event is obtained while the mailbox hasn't been completely
updated, so that one doesn't get the latest messages. What might
happen is that the directory is being updated during the readdir.

So I think that this is the real issue. But there may be other ones.

static void maildir_update_mtime (CONTEXT * ctx)
{
char buf[_POSIX_PATH_MAX];
struct stat st;
struct mh_data *data = mh_data (ctx);

if (ctx->magic == MUTT_MAILDIR)
{
snprintf (buf, sizeof (buf), "%s/%s", ctx->path, "cur");
if (stat (buf, &st) == 0)
data->mtime_cur = st.st_mtime;
snprintf (buf, sizeof (buf), "%s/%s", ctx->path, "new");
}
[...]

Isn't this a race condition? New mail could have been received before
the call to maildir_update_mtime (starting with opendir) and the
"stat". The recorded mtime should be one obtained before the opendir
in order to make sure not to miss any new message. But this is not
sufficient. But should parse the directory only when the current time
is strictly larger than the recorded mtime.

I think that with network file systems (such as NFS), this may not
even be sufficient if there is a shift between the times of the client
and the server. A solution may be to force a reparse of the directory
a few seconds after the mtime has last changed.

[Vincent Lefevre]

I've reported the bug on the BTS:

https://gitlab.com/muttmua/mutt/issues/44

[Kevin J. McCarthy]

Post by Vincent Lefevre

Post by Kevin J. McCarthy

Post by Kevin J. McCarthy
What if instead, we changed the code from a ">" comparison to
a "!=" comparison. This would force a rescan if the mtime were

This doesn't have any effect.

The maildir_check_mailbox() performs a stat first, then scans for new
mail. How is it that the messages are added during/after the scan but
the directory mtime doesn't change? If unison were resetting mtime, it
shouldn't be to the time when we scanned but didn't find all the
messages.

Post by Vincent Lefevre

Post by Kevin J. McCarthy
So, in effect, remove the call to maildir_update_mtime() at the end of
mh_sync_mailbox()?

This doesn't have any effect either.

This was for a different issue: the sync-mailbox race condition which I
believe is separate from the new mail detection issue you are seeing
with inotify.

Post by Vincent Lefevre
static void maildir_update_mtime (CONTEXT * ctx)
[...]
Isn't this a race condition? New mail could have been received before
the call to maildir_update_mtime (starting with opendir) and the
"stat".

This is called only during the initial mailbox open and when performing
a sync, so I believe is also a separate issue. Let's focus on the
main unison check-mailbox issue for now until I can make sense of it.

[Vincent Lefevre]

Post by Kevin J. McCarthy

Post by Vincent Lefevre

Post by Kevin J. McCarthy
What if instead, we changed the code from a ">" comparison to
a "!=" comparison. This would force a rescan if the mtime were

This doesn't have any effect.

The maildir_check_mailbox() performs a stat first, then scans for new
mail. How is it that the messages are added during/after the scan but
the directory mtime doesn't change? If unison were resetting mtime, it
shouldn't be to the time when we scanned but didn't find all the
messages.

I've just checked: unison doesn't reset the mtime on the "new"
directory. For instance:

Initially,

drwx------ 2 vlefevre vlefevre 135168 2018-06-11 15:22:00 new/

Then I ran unison, giving:

UNISON 2.48.3 started propagating changes at 15:22:07.33 on 11 Jun 2018
[...]
UNISON 2.48.3 finished propagating changes at 15:22:07.39 on 11 Jun 2018

and

drwx------ 2 vlefevre vlefevre 135168 2018-06-11 15:22:07 new/

BTW, it would be great if Mutt debug messages could contain timestamps
with a subsecond precision (even though unison doesn't detail the
timestamps between the above 2 messages).

[Vincent Lefevre]

Post by Vincent Lefevre
I think that there is a race condition with the inotify code: the
inotify event is obtained while the mailbox hasn't been completely
updated, so that one doesn't get the latest messages. What might
happen is that the directory is being updated during the readdir.

This is the problem. Mutt receives the inotify event and does the
opendir before the files are actually added to the directory. Thus
these files are not visible by readdir. I assume that when the files
are added, other mtime updates occur on the FS side, but since Mutt
uses a 1-second resolution, the mtime value doesn't appear to change.

Switching to a nanosecond resolution would probably solve the problem,
but I suppose that's not portable. As I suggested, a workaround is to
force a rescan a few seconds after this scan.