Re: [PATCH] travis-ci: run previously failed tests first, then slowest to fastest

From: Thomas Gummerer <t.gummerer@gmail.com>
Date: Jan 24, 2016, 14:34 UTC
Message-ID: <20160124143403.GL7100@hank>
In-Reply-To: <20160122060720.GA15681@sigill.intra.peff.net>

On 01/22, Jeff King wrote:

Show 25 quoted lines

> On Fri, Jan 22, 2016 at 12:52:55AM -0500, Jeff King wrote:
>
> > I get a few of the threads failing (in test 4) after 2-3 minutes. The
> > "-v" output is pretty unenlightening, though. I don't see anything
> > racy-looking in the test unless it is something with "read-tree" and
> > stat mtimes.
>
> And indeed, doing this:
>
> diff --git a/t/t0025-crlf-auto.sh b/t/t0025-crlf-auto.sh
> index c164b46..d34775b 100755
> --- a/t/t0025-crlf-auto.sh
> +++ b/t/t0025-crlf-auto.sh
> @@ -56,6 +56,7 @@ test_expect_success 'text=true causes a CRLF file to be normalized' '
>
>  	rm -f .gitattributes tmp LFonly CRLFonly LFwithNUL &&
>  	echo "CRLFonly text" > .gitattributes &&
> +	sleep 1 &&
>  	git read-tree --reset -u HEAD &&
>
>  	# Note, "normalized" means that git will normalize it if added
>
> let me run for over 5 minutes with no failures in test 4 (I eventually
> did hit one in test 9). I don't claim to understand what is going on,
> though.

I don't think this is the right solution though, I think this mostly lessens the load on the filesystem so the flakiness doesn't occur, especially on your system, where it seems hard to trigger in the first place :)

I actually hit the same problem occasionally when running the test suite before, but was always to lazy to try to reproduce it. Thanks to your reproduction I think I was able to track the underlying problem down.

My analysis is in the commit message below.

--->8---
Subject: [PATCH] entry: fix up to date marking

write_entry always marks cache entries up to date when state->refresh_cache is set. This is however not always accurate, if core.autocrlf is set in the config, a file with cr and lf line endings exists and the file attribute is set to text or crlf in the gitattributes.

Most notably this makes t0025 flaky. When calling deleting the files that will be adjusted through the automated crlf handling, and then calling `git read-tree --reset -u HEAD`, this leads to a race between git read-tree and the filesystem. The test currently only passes most of the time, because the filesystem usually isn't synced between the call to unpack_trees() and write_locked_index().

Currently the sequence of 1) remove files with cr and lf as line endings, 2) `git read-tree --reset -u HEAD` 3) checking the status of the changed files succeeds, because the index and the files are written at the same time, so they have the same mtime. Thus when reading the index the next time, the files are recognized as racy, and the actual contents on the disk are checked for changes.

If the index and the files have different mtimes however, the entry is written to the index as up to date because of the flag set in entry.c:write_entry(), and the contents on the filesystem are not actually checked again, because the stat data in the index matches.

The failures in t0025 can be consistently reproduced by introducing a call to sync() between the call to unpack_trees() and write_index_locked().

Instead of blindly marking and entry up to date in write_entry(), check if the contents may change on disk first, and strip the CE_UPTODATE flag in that case. Because the flag is not set, the cache entry will go through the racy check when writing the index the first time, and smudged if appropriate.

This fixes the flaky test as well as the underlying problem.

Signed-off-by: Thomas Gummerer <t.gummerer@gmail.com>
---
 entry.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/entry.c b/entry.c
index 582c400..102fdfa 100644
--- a/entry.c
+++ b/entry.c
@@ -214,6 +214,8 @@ finish:
 		if (!fstat_done)
 			lstat(ce->name, &st);
 		fill_stat_cache_info(ce, &st);
+		if (would_convert_to_git(ce->name))
+			ce->ce_flags &= ~CE_UPTODATE;
 		ce->ce_flags |= CE_UPDATE_IN_BASE;
 		state->istate->cache_changed |= CE_ENTRY_CHANGED;
 	}
--
2.7.0.75.g3ee1e0f.dirty