[PATCH 1/2] new: Don't update DB mtime if FS mtime equals wall-clock time.

[PATCH 1/2] new: Don't update DB mtime if FS mtime equals wall-clock time.

[Austin Clements]

This fixes a race where multiple message deliveries in the same second
with an intervening notmuch new could result in messages being ignored
by notmuch (at least, until a later delivery forced a rescan).
Because mtimes only have second granularity, later deliveries in the
same second won't change the directory mtime, and hence won't trigger
notmuch new to rescan the directory.  This situation can only occur
when notmuch new is being run at the same second as the directory's
modification time, so simply don't update the saved mtime in this
case.

This very race happens all over the test suite, and is currently
compensated for with increment_mtime (and, occasionally, luck).  With
this change, increment_mtime becomes unnecessary.
---
 notmuch-new.c |   20 +++++++++++++++++++-
 1 files changed, 19 insertions(+), 1 deletions(-)

diff --git a/notmuch-new.c b/notmuch-new.c
index 0fa2a3c..c180591 100644
--- a/notmuch-new.c
+++ b/notmuch-new.c
@@ -213,6 +213,7 @@ _entries_resemble_maildir (struct dirent **entries, int count)
  *     information is lost from the database).
  *
  *   o Tell the database to update its time of 'path' to 'fs_mtime'
+ *     if fs_mtime isn't the current wall-clock time.
  */
 static notmuch_status_t
 add_files_recursive (notmuch_database_t *notmuch,
@@ -230,6 +231,7 @@ add_files_recursive (notmuch_database_t *notmuch,
     notmuch_directory_t *directory;
     notmuch_filenames_t *db_files = NULL;
     notmuch_filenames_t *db_subdirs = NULL;
+    time_t stat_time;
     struct stat st;
     notmuch_bool_t is_maildir, new_directory;
     const char **tag;
@@ -239,6 +241,7 @@ add_files_recursive (notmuch_database_t *notmuch,
 		 path, strerror (errno));
 	return NOTMUCH_STATUS_FILE_ERROR;
     }
+    stat_time = time (NULL);
 
     /* This is not an error since we may have recursed based on a
      * symlink to a regular file, not a directory, and we don't know
@@ -509,7 +512,22 @@ add_files_recursive (notmuch_database_t *notmuch,
 	notmuch_filenames_move_to_next (db_subdirs);
     }
 
-    if (! interrupted) {
+    /* If the directory's mtime is the same as the wall-clock time
+     * when we stat'ed the directory, we skip updating the mtime in
+     * the database because a message could be delivered later in this
+     * same second.  This may lead to unnecessary re-scans, but it
+     * avoids overlooking messages.
+     *
+     * XXX Bug workaround: If this is a new directory, we *must*
+     * update the mtime; otherwise the next run will see the 0 mtime
+     * and think this is still a new directory containing no files or
+     * subdirs (which is unsound in general).  If fs_mtime ==
+     * stat_time, we set the database mtime to a bogus (but non-zero!)
+     * value to force a rescan.
+     */
+    if (new_directory && fs_mtime == stat_time)
+	fs_mtime = 1;
+    if (! interrupted && fs_mtime != stat_time) {
 	status = notmuch_directory_set_mtime (directory, fs_mtime);
 	if (status && ret == NOTMUCH_STATUS_SUCCESS)
 	    ret = status;
-- 
1.7.5.1

[PATCH 2/2] test: Nix increment_mtime.

[Austin Clements]

With the fix for the mtime race, this workaround is no longer
necessary.
---
 test/maildir-sync     |    8 --------
 test/multipart        |    1 -
 test/new              |    9 ---------
 test/search-by-folder |    2 --
 test/test-lib.sh      |   15 ---------------
 5 files changed, 0 insertions(+), 35 deletions(-)

diff --git a/test/maildir-sync b/test/maildir-sync
index c99dbec..a60854f 100755
--- a/test/maildir-sync
+++ b/test/maildir-sync
@@ -23,7 +23,6 @@ output=$(notmuch search subject:"Adding S flag" | notmuch_search_sanitize)
 output+="
 "
 mv "${gen_msg_filename}" "${gen_msg_filename}S"
-increment_mtime "$(dirname "${gen_msg_filename}")"
 output+=$(NOTMUCH_NEW)
 output+="
 "
@@ -66,7 +65,6 @@ test_expect_equal "$output" '[[[{"id": "adding-replied-tag@notmuch-test-suite",
 test_expect_success 'notmuch reply works with renamed file (without notmuch new)' 'notmuch reply id:${gen_msg_id}'
 
 test_begin_subtest "notmuch new detects no file rename after tag->flag synchronization"
-increment_mtime "$(dirname ${gen_msg_filename})"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail."
 
@@ -77,7 +75,6 @@ output=$(cd "$MAIL_DIR/cur"; ls message-to-move*)
 test_expect_equal "$output" "message-to-move-to-cur:2,S"
 
 test_begin_subtest "No rename should be detected by notmuch new"
-increment_mtime "$MAIL_DIR/cur"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail."
 # (*) If notmuch new was not run we've got "Processed 1 file in almost
@@ -97,7 +94,6 @@ output=$(notmuch search subject:"Removing S flag" | notmuch_search_sanitize)
 output+="
 "
 mv "${gen_msg_filename}" "${gen_msg_filename%S}"
-increment_mtime "$(dirname "${gen_msg_filename}")"
 output+=$(NOTMUCH_NEW)
 output+="
 "
@@ -110,7 +106,6 @@ test_begin_subtest "Removing info from filename leaves tags unchanged"
 add_message [subject]='"Message to lose maildir info"' [filename]='message-to-lose-maildir-info' [dir]=cur
 notmuch tag -unread subject:"Message to lose maildir info"
 mv "$MAIL_DIR/cur/message-to-lose-maildir-info:2,S" "$MAIL_DIR/cur/message-without-maildir-info"
-increment_mtime "$MAIL_DIR/cur"
 output=$(NOTMUCH_NEW)
 output+="
 "
@@ -134,7 +129,6 @@ mv $MAIL_DIR/cur/adding-replied-tag:2,RS $MAIL_DIR/cur/adding-replied-tag:2,S
 mv $MAIL_DIR/cur/adding-s-flag:2,S $MAIL_DIR/cur/adding-s-flag:2,
 mv $MAIL_DIR/cur/adding-with-s-flag:2,S $MAIL_DIR/cur/adding-with-s-flag:2,RS
 mv $MAIL_DIR/cur/message-to-move-to-cur:2,S $MAIL_DIR/cur/message-to-move-to-cur:2,DS
-increment_mtime $MAIL_DIR/cur
 notmuch dump dump.txt
 NOTMUCH_NEW >/dev/null
 notmuch restore dump.txt
@@ -144,7 +138,6 @@ test_expect_equal "$output" "$expected"
 test_begin_subtest 'Adding flags to duplicate message tags the mail'
 add_message [subject]='"Duplicated message"' [dir]=cur [filename]='duplicated-message:2,'
 cp "$MAIL_DIR/cur/duplicated-message:2," "$MAIL_DIR/cur/duplicated-message-copy:2,RS"
-increment_mtime $MAIL_DIR/cur
 NOTMUCH_NEW > output
 notmuch search subject:"Duplicated message" | notmuch_search_sanitize >> output
 test_expect_equal "$(< output)" "No new mail.
@@ -152,7 +145,6 @@ thread:XXX   2001-01-05 [1/1] Notmuch Test Suite; Duplicated message (inbox repl
 
 test_begin_subtest "Adding duplicate message without flags does not remove tags"
 cp "$MAIL_DIR/cur/duplicated-message-copy:2,RS" "$MAIL_DIR/cur/duplicated-message-another-copy:2,"
-increment_mtime $MAIL_DIR/cur
 NOTMUCH_NEW > output
 notmuch search subject:"Duplicated message" | notmuch_search_sanitize >> output
 test_expect_equal "$(< output)" "No new mail.
diff --git a/test/multipart b/test/multipart
index 4d577f8..22c42c6 100755
--- a/test/multipart
+++ b/test/multipart
@@ -88,7 +88,6 @@ Content-Transfer-Encoding: base64
 7w0K
 --==-=-=--
 EOF
-increment_mtime "$MAIL_DIR"
 notmuch new > /dev/null
 
 test_begin_subtest "--format=text --part=0, full message"
diff --git a/test/new b/test/new
index 1b7296e..49f390d 100755
--- a/test/new
+++ b/test/new
@@ -52,10 +52,8 @@ generate_message
 tmp_msg_filename=tmp/"$gen_msg_filename"
 mkdir -p "$(dirname "$tmp_msg_filename")"
 mv "$gen_msg_filename" "$tmp_msg_filename"
-increment_mtime "${MAIL_DIR}"
 notmuch new > /dev/null
 mv "$tmp_msg_filename" "$gen_msg_filename"
-increment_mtime "${MAIL_DIR}"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "Added 1 new message to the database."
 
@@ -65,7 +63,6 @@ test_begin_subtest "Renamed message"
 generate_message
 notmuch new > /dev/null
 mv "$gen_msg_filename" "${gen_msg_filename}"-renamed
-increment_mtime "${MAIL_DIR}"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Detected 1 file rename."
 
@@ -73,7 +70,6 @@ test_expect_equal "$output" "No new mail. Detected 1 file rename."
 test_begin_subtest "Deleted message"
 
 rm "${gen_msg_filename}"-renamed
-increment_mtime "${MAIL_DIR}"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Removed 1 message."
 
@@ -87,7 +83,6 @@ generate_message [dir]=dir
 notmuch new > /dev/null
 
 mv "${MAIL_DIR}"/dir "${MAIL_DIR}"/dir-renamed
-increment_mtime "${MAIL_DIR}"
 
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Detected 3 file renames."
@@ -96,7 +91,6 @@ test_expect_equal "$output" "No new mail. Detected 3 file renames."
 test_begin_subtest "Deleted directory"
 
 rm -rf "${MAIL_DIR}"/dir-renamed
-increment_mtime "${MAIL_DIR}"
 
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Removed 3 messages."
@@ -115,7 +109,6 @@ test_expect_equal "$output" "Added 3 new messages to the database."
 test_begin_subtest "Deleted directory (end of list)"
 
 rm -rf "${MAIL_DIR}"/zzz
-increment_mtime "${MAIL_DIR}"
 
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Removed 3 messages."
@@ -139,7 +132,6 @@ external_msg_filename="$PWD"/external/"$(basename "$gen_msg_filename")"
 mkdir -p "$(dirname "$external_msg_filename")"
 mv "$gen_msg_filename" "$external_msg_filename"
 ln -s "$external_msg_filename" "$gen_msg_filename"
-increment_mtime "${MAIL_DIR}"
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "Added 1 new message to the database."
 
@@ -157,7 +149,6 @@ test_expect_equal "$output" "Added 3 new messages to the database."
 test_begin_subtest "Deleted two-level directory"
 
 rm -rf "${MAIL_DIR}"/two
-increment_mtime "${MAIL_DIR}"
 
 output=$(NOTMUCH_NEW)
 test_expect_equal "$output" "No new mail. Removed 3 messages."
diff --git a/test/search-by-folder b/test/search-by-folder
index 4afa483..5cc2ca8 100755
--- a/test/search-by-folder
+++ b/test/search-by-folder
@@ -23,14 +23,12 @@ test_expect_equal "$output" "thread:XXX   2001-01-05 [1/1] Notmuch Test Suite; B
 
 test_begin_subtest "After removing duplicate instance of matching path"
 rm -r "${MAIL_DIR}/bad/news"
-increment_mtime "${MAIL_DIR}/bad"
 notmuch new
 output=$(notmuch search folder:bad/news | notmuch_search_sanitize)
 test_expect_equal "$output" "thread:XXX   2001-01-05 [1/1] Notmuch Test Suite; Bears (inbox unread)"
 
 test_begin_subtest "After rename, old path returns nothing"
 mv "${MAIL_DIR}/duplicate/bad/news" "${MAIL_DIR}/duplicate/bad/olds"
-increment_mtime "${MAIL_DIR}/duplicate/bad"
 notmuch new
 output=$(notmuch search folder:bad/news | notmuch_search_sanitize)
 test_expect_equal "$output" ""
diff --git a/test/test-lib.sh b/test/test-lib.sh
index 079d7db..22e387e 100755
--- a/test/test-lib.sh
+++ b/test/test-lib.sh
@@ -213,16 +213,6 @@ remove_cr () {
 	tr '\015' Q | sed -e 's/Q$//'
 }
 
-# Notmuch helper functions
-increment_mtime_amount=0
-increment_mtime ()
-{
-    dir="$1"
-
-    increment_mtime_amount=$((increment_mtime_amount + 1))
-    touch -d "+${increment_mtime_amount} seconds" "$dir"
-}
-
 # Generate a new message in the mail directory, with a unique message
 # ID and subject. The message is not added to the index.
 #
@@ -364,9 +354,6 @@ Date: ${template[date]}
 ${additional_headers}
 ${template[body]}
 EOF
-
-    # Ensure that the mtime of the containing directory is updated
-    increment_mtime "$(dirname "${gen_msg_filename}")"
 }
 
 # Generate a new message and add it to the database.
@@ -409,8 +396,6 @@ emacs_deliver_message ()
 	   $@
 	   (message-send-and-exit))" >/dev/null 2>&1
     wait ${smtp_dummy_pid}
-    increment_mtime "$MAIL_DIR"/sent/cur
-    increment_mtime "$MAIL_DIR"/sent/new
     notmuch new >/dev/null
 }
 
-- 
1.7.5.1

Re: [PATCH 1/2] new: Don't update DB mtime if FS mtime equals wall-clock time.

[Carl Worth]

[-- Attachment #1: Type: text/plain, Size: 1000 bytes --]

On Wed, 29 Jun 2011 03:10:54 -0400, Austin Clements <amdragon@MIT.EDU> wrote:
> This fixes a race where multiple message deliveries in the same second
> with an intervening notmuch new could result in messages being ignored
> by notmuch (at least, until a later delivery forced a rescan).

Thanks for the fix, Austin!

> +     * XXX Bug workaround: If this is a new directory, we *must*
> +     * update the mtime; otherwise the next run will see the 0 mtime
> +     * and think this is still a new directory containing no files or
> +     * subdirs (which is unsound in general).  If fs_mtime ==
> +     * stat_time, we set the database mtime to a bogus (but non-zero!)
> +     * value to force a rescan.

I like to reserve "XXX" as an indication that some further work is
necessary.

That doesn't seem to be the case here, (instead, you seem to have
thought this issue out quite fully).

Other than that, I'm quite happy with the patch.

-Carl

-- 
carl.d.worth@intel.com

[-- Attachment #2: Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 1/2] new: Don't update DB mtime if FS mtime equals wall-clock time.

[Carl Worth]

[-- Attachment #1: Type: text/plain, Size: 735 bytes --]

On Wed, 29 Jun 2011 06:47:37 -0700, Carl Worth <cworth@cworth.org> wrote:
> On Wed, 29 Jun 2011 03:10:54 -0400, Austin Clements <amdragon@MIT.EDU> wrote:
> > +     * XXX Bug workaround: If this is a new directory, we *must*
> > +     * update the mtime; otherwise the next run will see the 0 mtime
...
> I like to reserve "XXX" as an indication that some further work is
> necessary.

Reading your other mail now, I see that there are bugs here and that you
do want to eliminate the new_directory optimization. That wasn't clear
to me from the comment above.

So the XXX is probably fine, but could perhaps give a little more
indication of what could be done to eliminate the bug.

-Carl

-- 
carl.d.worth@intel.com

[-- Attachment #2: Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 1/2] new: Don't update DB mtime if FS mtime equals wall-clock time.

[Carl Worth]

[-- Attachment #1: Type: text/plain, Size: 657 bytes --]

On Wed, 29 Jun 2011 03:10:54 -0400, Austin Clements <amdragon@MIT.EDU> wrote:
> This fixes a race where multiple message deliveries in the same second
> with an intervening notmuch new could result in messages being ignored
> by notmuch (at least, until a later delivery forced a rescan).

Excellent fix, Austin.

I've merged this, (and the following commit to drop the ugly
increment_mtime).

I think that even fixes an outstanding portability bug (where someone
previously sent patches to change our implementation of
increment_mtime).

It's sure nice to see notmuch become more robust all the time.

-Carl

-- 
carl.d.worth@intel.com

[-- Attachment #2: Type: application/pgp-signature, Size: 197 bytes --]