From: Mike Larkin <mlarkin@nested.page>
Subject: Re: patch: regress: Work around glitchy clocks in vmm guests
To: Steven McDonald <steven@steven-mcdonald.id.au>
Cc: gameoftrees@openbsd.org
Date: Sat, 28 Sep 2019 15:50:38 -0700

What timecounter are your guests using?

They should be using pvclock or tsc.

On Sun, Sep 29, 2019 at 12:33:13AM +0200, Steven McDonald wrote:
> Some tests fail intermittently in vmm because the clock does not
> advance between steps, resulting in files that should have a newer
> mtime than the repo metadata but don't. Example failure:
>
>   test_status_shows_local_mods_after_update --- /tmp/got-test-status_shows_local_mods_after_update-duAj87aL/stdout.expected       Sun Sep 29 00:18:36 2019
>   +++ /tmp/got-test-status_shows_local_mods_after_update-duAj87aL/stdout  Sun Sep 29 00:18:36 2019
>   @@ -1 +0,0 @@
>   -M  numbers
>   test failed; leaving test data in /tmp/got-test-status_shows_local_mods_after_update-duAj87aL
>
> Comparing the mtime on the 'numbers' file with that in .got/file-index
> shows that the timestamps are identical, which is why got does not
> treat this file as modified.
>
> This intermittent behaviour can be observed outside the context of got
> (here, x is a small program that just calls stat(2) on foo and displays
> the mtime):
>
>   $ echo a >foo; ./x; echo b >foo; ./x
>   1569708831.911759175
>   1569708831.931539267
>   $ echo a >foo; ./x; echo b >foo; ./x
>   1569708832.741842903
>   1569708832.741842903
>
> This is unlikely to be a problem in real-world usage because humans
> aren't as fast as these regression tests, so I think working around it
> in the tests is sufficient.
>
> The below diff makes this work consistently; sleeping for a nanosecond
> is sufficient because we just need the clock to advance by any amount
> at all.
>
> Better suggestions/OKs?
>
> diff --git a/regress/cmdline/commit.sh b/regress/cmdline/commit.sh
> index 55340c7..3413152 100755
> --- a/regress/cmdline/commit.sh
> +++ b/regress/cmdline/commit.sh
> @@ -262,6 +262,7 @@ function test_commit_rejects_conflicted_file {
>  	git_show_head $testroot/repo >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
> diff --git a/regress/cmdline/diff.sh b/regress/cmdline/diff.sh
> index 455469c..2036892 100755
> --- a/regress/cmdline/diff.sh
> +++ b/regress/cmdline/diff.sh
> @@ -121,6 +121,7 @@ function test_diff_shows_conflict {
>  	echo -n "Updated to commit $head_rev" >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
> diff --git a/regress/cmdline/stage.sh b/regress/cmdline/stage.sh
> index c847136..703285f 100755
> --- a/regress/cmdline/stage.sh
> +++ b/regress/cmdline/stage.sh
> @@ -253,6 +253,7 @@ function test_stage_conflict {
>  	git_show_head $testroot/repo >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
> @@ -1241,6 +1242,7 @@ function test_stage_commit_out_of_date {
>  	fi
>
>  	(cd $testroot/wt && got unstage > /dev/null)
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>  	ret="$?"
>  	if [ "$ret" != "0" ]; then
> @@ -1306,6 +1308,7 @@ function test_stage_commit {
>  	echo "modified file" > $testroot/wt/alpha
>  	(cd $testroot/wt && got stage alpha beta foo > /dev/null)
>
> +	sleep 0.000000001  # vmm clock workaround
>  	echo "modified file again" > $testroot/wt/alpha
>  	echo "new file changed" > $testroot/wt/foo
>  	echo "non-staged change" > $testroot/wt/gamma/delta
> diff --git a/regress/cmdline/status.sh b/regress/cmdline/status.sh
> index 5fde224..c8ed4a7 100755
> --- a/regress/cmdline/status.sh
> +++ b/regress/cmdline/status.sh
> @@ -188,6 +188,7 @@ function test_status_shows_local_mods_after_update {
>  	git_show_head $testroot/repo >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
> @@ -319,6 +320,7 @@ function test_status_shows_no_mods_after_complete_merge {
>  	git_show_head $testroot/repo >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
> @@ -373,6 +375,7 @@ function test_status_shows_conflict {
>  	git_show_head $testroot/repo >> $testroot/stdout.expected
>  	echo >> $testroot/stdout.expected
>
> +	sleep 0.000000001  # vmm clock workaround
>  	(cd $testroot/wt && got update > $testroot/stdout)
>
>  	cmp -s $testroot/stdout.expected $testroot/stdout
>