t7063 failure on FreeBSD 10.3 i386/amd64

t7063 failure on FreeBSD 10.3 i386/amd64

[Eric Wong]

Not sure what's going on, below is the relevant output when
run with -i -v --tee (the rest succeeds without -i):

ok 26 - untracked cache correct after status

expecting success: 
	avoid_racy &&
	: >../trace &&
	GIT_TRACE_UNTRACKED_STATS="$TRASH_DIRECTORY/trace" \
	git status --porcelain >../status.actual &&
	cat >../status.expect <<EOF &&
 M done/two
?? .gitignore
?? done/five
?? dtwo/
EOF
	test_cmp ../status.expect ../status.actual &&
	cat >../trace.expect <<EOF &&
node creation: 0
gitignore invalidation: 0
directory invalidation: 0
opendir: 0
EOF
	test_cmp ../trace.expect ../trace

--- ../trace.expect	2016-07-18 22:23:28.679886000 +0000
+++ ../trace	2016-07-18 22:23:28.677135000 +0000
@@ -1,4 +1,4 @@
 node creation: 0
 gitignore invalidation: 0
-directory invalidation: 0
-opendir: 0
+directory invalidation: 1
+opendir: 1
not ok 27 - test sparse status again with untracked cache

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Eric Wong]

Oops, forgot to Cc some folks who worked on this :x

Filesystem is ufs and it fails regardless of whether
soft-updates is enabled or not.

Eric Wong <e@80x24.org> wrote:
> Not sure what's going on, below is the relevant output when
> run with -i -v --tee (the rest succeeds without -i):
> 
> ok 26 - untracked cache correct after status
> 
> expecting success: 
> 	avoid_racy &&
> 	: >../trace &&
> 	GIT_TRACE_UNTRACKED_STATS="$TRASH_DIRECTORY/trace" \
> 	git status --porcelain >../status.actual &&
> 	cat >../status.expect <<EOF &&
>  M done/two
> ?? .gitignore
> ?? done/five
> ?? dtwo/
> EOF
> 	test_cmp ../status.expect ../status.actual &&
> 	cat >../trace.expect <<EOF &&
> node creation: 0
> gitignore invalidation: 0
> directory invalidation: 0
> opendir: 0
> EOF
> 	test_cmp ../trace.expect ../trace
> 
> --- ../trace.expect	2016-07-18 22:23:28.679886000 +0000
> +++ ../trace	2016-07-18 22:23:28.677135000 +0000
> @@ -1,4 +1,4 @@
>  node creation: 0
>  gitignore invalidation: 0
> -directory invalidation: 0
> -opendir: 0
> +directory invalidation: 1
> +opendir: 1
> not ok 27 - test sparse status again with untracked cache

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Duy Nguyen]

On Tue, Jul 19, 2016 at 12:54 AM, Eric Wong <e@80x24.org> wrote:
> Oops, forgot to Cc some folks who worked on this :x
>
> Filesystem is ufs and it fails regardless of whether
> soft-updates is enabled or not.

Nothing stands out to my eyes, so I'm going to install freebsd this
weekend. I hope ufs does not have any nasty surprise for me. Stay
tuned.
-- 
Duy

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Eric Wong]

Duy Nguyen <pclouds@gmail.com> wrote:
> On Tue, Jul 19, 2016 at 12:54 AM, Eric Wong <e@80x24.org> wrote:
> > Oops, forgot to Cc some folks who worked on this :x
> >
> > Filesystem is ufs and it fails regardless of whether
> > soft-updates is enabled or not.
> 
> Nothing stands out to my eyes, so I'm going to install freebsd this
> weekend. I hope ufs does not have any nasty surprise for me. Stay
> tuned.

Thanks, this problem might be ufs-specific, tmpfs is fine.
Tested tmpfs with:

	kldload tmpfs
	mkdir /tmp/tmpfs
	mount -t tmpfs tmpfs /tmp/tmpfs

(Documenting all this since much of this is new to me)

I noticed FreeBSD now provides ready-to-run VM images along with
normal installation stuff, including qcow2 ones for QEMU users,
so that saves some time.

http://ftp.freebsd.org/pub/FreeBSD/releases/VM-IMAGES/10.3-RELEASE/amd64/Latest/FreeBSD-10.3-RELEASE-amd64.qcow2.xz

Notes:

* "-net user" because I'm lazy (ICMP ping won't work out-of-the-box)

* kvm can be substituted for qemu-system-$ARCH for the KVM-less
  or users lacking write access to /dev/kvm

* hostfwd=... allows me to ssh into port 22215 from my Linux host
  to hit port 22 in the guest

* "dhclient vtnet0 && pkg install git gettext gmake python libiconv"
  should be enough to get started

kvm -smp 8 -m 2048 \
	-drive if=virtio,file=FreeBSD-10.3-RELEASE-amd64.qcow2 \
	-net nic,model=virtio \
	-net user,hostfwd=tcp:127.0.0.1:22215-:22 \
	-display curses

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Duy Nguyen]

On Wed, Jul 20, 2016 at 5:02 AM, Eric Wong <e@80x24.org> wrote:
> Duy Nguyen <pclouds@gmail.com> wrote:
>> On Tue, Jul 19, 2016 at 12:54 AM, Eric Wong <e@80x24.org> wrote:
>> > Oops, forgot to Cc some folks who worked on this :x
>> >
>> > Filesystem is ufs and it fails regardless of whether
>> > soft-updates is enabled or not.
>>
>> Nothing stands out to my eyes, so I'm going to install freebsd this
>> weekend. I hope ufs does not have any nasty surprise for me. Stay
>> tuned.
>
> Thanks, this problem might be ufs-specific, tmpfs is fine.
> Tested tmpfs with:
>
>         kldload tmpfs
>         mkdir /tmp/tmpfs
>         mount -t tmpfs tmpfs /tmp/tmpfs
>
> (Documenting all this since much of this is new to me)

If you can, try with some other "real" filesystems, not virtual ones
like tmpfs, e.g. zfs or ext2 (not sure if it's supported on fbsd).
This is just to make sure I didn't hit a bug specific to fbsd. Don't
worry if you don't have time to do it. I'll get to it eventually.

> I noticed FreeBSD now provides ready-to-run VM images along with
> normal installation stuff, including qcow2 ones for QEMU users,
> so that saves some time.
>
> http://ftp.freebsd.org/pub/FreeBSD/releases/VM-IMAGES/10.3-RELEASE/amd64/Latest/FreeBSD-10.3-RELEASE-amd64.qcow2.xz

Yeah that's what I'm going to do, but not right now..
-- 
Duy

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Duy Nguyen]

On Tue, Jul 19, 2016 at 6:12 PM, Duy Nguyen <pclouds@gmail.com> wrote:
> On Tue, Jul 19, 2016 at 12:54 AM, Eric Wong <e@80x24.org> wrote:
>> Oops, forgot to Cc some folks who worked on this :x
>>
>> Filesystem is ufs and it fails regardless of whether
>> soft-updates is enabled or not.
>
> Nothing stands out to my eyes, so I'm going to install freebsd this
> weekend. I hope ufs does not have any nasty surprise for me. Stay
> tuned.

The good news is it looks like a false alarm due to a racy test (and
it happens on ext2 too, zfs not tested), no big flaw or anything
(phew!). The bad news is, I still have no idea what's happening and
why is_racy_stat() returns true in this particular case. It'll take
some more time...
-- 
Duy

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Duy Nguyen]

On Wed, Jul 27, 2016 at 07:33:17PM +0200, Duy Nguyen wrote:
> On Tue, Jul 19, 2016 at 6:12 PM, Duy Nguyen <pclouds@gmail.com> wrote:
> > On Tue, Jul 19, 2016 at 12:54 AM, Eric Wong <e@80x24.org> wrote:
> >> Oops, forgot to Cc some folks who worked on this :x
> >>
> >> Filesystem is ufs and it fails regardless of whether
> >> soft-updates is enabled or not.
> >
> > Nothing stands out to my eyes, so I'm going to install freebsd this
> > weekend. I hope ufs does not have any nasty surprise for me. Stay
> > tuned.
> 
> The good news is it looks like a false alarm due to a racy test (and
> it happens on ext2 too, zfs not tested), no big flaw or anything
> (phew!). The bad news is, I still have no idea what's happening and
> why is_racy_stat() returns true in this particular case. It'll take
> some more time...

I give up. FreeBSD behaves so weird in this case.

The code of interest is this

    test_expect_success 'test sparse status with untracked cache' '
    	: >../trace &&
    	avoid_racy &&
    	GIT_TRACE_UNTRACKED_STATS="$TRASH_DIRECTORY/trace" \
    	git status --porcelain >../status.actual &&
    	...
    '

For some reason mtime of current directory is always latest time when
git makes the stat call. Even if I make avoid_racy sleep longer,
several seconds, mtime of "." will be the latest time.

But cwd stat info is _not_ supposed to change! We haven't touched it
while avoid_racy is running. avoid_racy is just a wrapper of
sleep. And sleep does not change cwd's mtime from the shell prompt. I
tried running the script with bash too (suspecting problem with
default shell) and replaced avoid_racy with /bin/sleep. Nothing.

Does our test framework run something in background??? No, it
can't be.

If a stat call is made before avoid_racy, then mtime is pinned down
and does not change anymore. So a "fix" is something like this. I
tried a minimal program that just does "stat" to make sure it's stat
that does it, not some side effect from 'ls'.

diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index 38b3890..fd199a0 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -421,6 +421,7 @@ test_expect_success 'create/modify files, some of which are gitignored' '
 
 test_expect_success 'test sparse status with untracked cache' '
        : >../trace &&
+       ls -d . &&
        avoid_racy &&
        GIT_TRACE_UNTRACKED_STATS="$TRASH_DIRECTORY/trace" \
        git status --porcelain >../status.actual &&

--
Duy

Re: t7063 failure on FreeBSD 10.3 i386/amd64

[Duy Nguyen]

On Sat, Jul 30, 2016 at 3:31 PM, Duy Nguyen <pclouds@gmail.com> wrote:
> I give up.

I lied. Sleeping 30 seconds in that test case works, but there is no
way I'm sending a patch to delay 30 seconds. FreeBSD must have some
delayed mtime update "feature" in its vfs layer somewhere.

Now I give up.
-- 
Duy

[PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Nguyễn Thái Ngọc Duy]

Let's start with the commit message of [1] from freebsd.git [2]

    Sync timestamp changes for inodes of special files to disk as late
    as possible (when the inode is reclaimed).  Temporarily only do
    this if option UFS_LAZYMOD configured and softupdates aren't
    enabled.  UFS_LAZYMOD is intentionally left out of
    /sys/conf/options.

    This is mainly to avoid almost useless disk i/o on battery powered
    machines.  It's silly to write to disk (on the next sync or when
    the inode becomes inactive) just because someone hit a key or
    something wrote to the screen or /dev/null.

    PR:             5577 [3]

The short version of that, in the context of t7063, is that when a
directory is updated, its mtime may be updated later, not
immediately. This can be shown with a simple command sequence

    date; sleep 1; touch abc; rm abc; sleep 10; ls -lTd .

One would expect that the date shown in `ls` would be one second from
`date`, but it's 10 seconds later. If we put another `ls -lTd .` in
front of `sleep 10`, then the date of the last `ls` comes as
expected. The first `ls` somehow forces mtime to be updated.

t7063 is really sensitive to directory mtime. When mtime is too "new",
git code suspects racy timestamps and will not trigger the shortcut in
untracked cache, in t7063.26 (or t7063.25 before this patch) and
eventually be detected in t7063.28

We have two options thanks to this special FreeBSD feature:

1) Stop supporting untracked cache on FreeBSD. Skip t7063 entirely
   when running on FreeBSD

2) Work around this problem (using the same 'ls' trick) and continue
   to support untracked cache on FreeBSD

I initially wanted to go with 1) because I didn't know the exact
nature of this feature and feared that it would make untracked cache
work unreliably, using the cached version when it should not.

Since the behavior of this thing is clearer now. The picture is not
that bad. If this indeed happens often, untracked cache would assume
racy condition more often and _fall back_ to non-untracked cache code
paths. Which means it may be less effective, but it will not show
wrong things.

This patch goes with option 2.

PS. For those who want to look further in FreeBSD source code, this
flag is now called IN_LAZYMOD. I can see it's effective in ext2 and
ufs. zfs is questionable.

[1] 660e6408e6df99a20dacb070c5e7f9739efdf96d
[2] git://github.com/freebsd/freebsd.git
[3] https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=5577

Reported-by: Eric Wong <e@80x24.org>
Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
---
 This is only of those commits that commit messages are more important
 than the patch itself. One of the good notes about directory mtime,
 if we start to use it in more places in git.

 t/t7063-status-untracked-cache.sh | 4 ++++
 t/test-lib.sh                     | 6 ++++++
 2 files changed, 10 insertions(+)

diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index a971884..08fc586 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -419,6 +419,10 @@ test_expect_success 'create/modify files, some of which are gitignored' '
 	rm base
 '
 
+test_expect_success FREEBSD 'Work around lazy mtime update' '
+	ls -ld . >/dev/null
+'
+
 test_expect_success 'test sparse status with untracked cache' '
 	: >../trace &&
 	avoid_racy &&
diff --git a/t/test-lib.sh b/t/test-lib.sh
index 0055ebb..3c730a2 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -961,6 +961,12 @@ case $(uname -s) in
 	test_set_prereq SED_STRIPS_CR
 	test_set_prereq GREP_STRIPS_CR
 	;;
+*FreeBSD*)
+	test_set_prereq FREEBSD
+	test_set_prereq POSIXPERM
+	test_set_prereq BSLASHPSPEC
+	test_set_prereq EXECKEEPSPID
+	;;
 *)
 	test_set_prereq POSIXPERM
 	test_set_prereq BSLASHPSPEC
-- 
2.9.1.566.gbd532d4

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Eric Wong]

Nguyễn Thái Ngọc Duy <pclouds@gmail.com> wrote:
> Let's start with the commit message of [1] from freebsd.git [2]
> 
>     Sync timestamp changes for inodes of special files to disk as late
>     as possible (when the inode is reclaimed).  Temporarily only do
>     this if option UFS_LAZYMOD configured and softupdates aren't
>     enabled.  UFS_LAZYMOD is intentionally left out of
>     /sys/conf/options.
> 
>     This is mainly to avoid almost useless disk i/o on battery powered
>     machines.  It's silly to write to disk (on the next sync or when
>     the inode becomes inactive) just because someone hit a key or
>     something wrote to the screen or /dev/null.
> 
>     PR:             5577 [3]
> 
> The short version of that, in the context of t7063, is that when a
> directory is updated, its mtime may be updated later, not
> immediately. This can be shown with a simple command sequence
> 
>     date; sleep 1; touch abc; rm abc; sleep 10; ls -lTd .

Yikes.  I guess FreeBSD doesn't have an in-memory inode cache it
can keep up-to-date without flushing to disk?

> One would expect that the date shown in `ls` would be one second from
> `date`, but it's 10 seconds later. If we put another `ls -lTd .` in
> front of `sleep 10`, then the date of the last `ls` comes as
> expected. The first `ls` somehow forces mtime to be updated.

Fwiw, `stat .` seems to have the same effect as `ls -lTd .`...

> t7063 is really sensitive to directory mtime. When mtime is too "new",
> git code suspects racy timestamps and will not trigger the shortcut in
> untracked cache, in t7063.26 (or t7063.25 before this patch) and
> eventually be detected in t7063.28
> 
> We have two options thanks to this special FreeBSD feature:
> 
> 1) Stop supporting untracked cache on FreeBSD. Skip t7063 entirely
>    when running on FreeBSD
> 
> 2) Work around this problem (using the same 'ls' trick) and continue
>    to support untracked cache on FreeBSD
> 
> I initially wanted to go with 1) because I didn't know the exact
> nature of this feature and feared that it would make untracked cache
> work unreliably, using the cached version when it should not.
> 
> Since the behavior of this thing is clearer now. The picture is not
> that bad. If this indeed happens often, untracked cache would assume
> racy condition more often and _fall back_ to non-untracked cache code
> paths. Which means it may be less effective, but it will not show
> wrong things.
> 
> This patch goes with option 2.
> 
> PS. For those who want to look further in FreeBSD source code, this
> flag is now called IN_LAZYMOD. I can see it's effective in ext2 and
> ufs. zfs is questionable.
> 
> [1] 660e6408e6df99a20dacb070c5e7f9739efdf96d
> [2] git://github.com/freebsd/freebsd.git
> [3] https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=5577
> 
> Reported-by: Eric Wong <e@80x24.org>
> Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
> ---
>  This is only of those commits that commit messages are more important
>  than the patch itself. One of the good notes about directory mtime,
>  if we start to use it in more places in git.

Thanks, Tested-by: Eric Wong <e@80x24.org>

>  t/t7063-status-untracked-cache.sh | 4 ++++
>  t/test-lib.sh                     | 6 ++++++
>  2 files changed, 10 insertions(+)
> 
> diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
> index a971884..08fc586 100755
> --- a/t/t7063-status-untracked-cache.sh
> +++ b/t/t7063-status-untracked-cache.sh
> @@ -419,6 +419,10 @@ test_expect_success 'create/modify files, some of which are gitignored' '
>  	rm base
>  '
>  
> +test_expect_success FREEBSD 'Work around lazy mtime update' '
> +	ls -ld . >/dev/null
> +'

	stat . >/dev/null

would be more to the point of what is going on, here.   But I
also wonder if untracked cache itself could/should be doing this
internally.

(I'm not familiar with that code, of course)

Thanks again for looking into this.

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Eric Wong]

Eric Wong <e@80x24.org> wrote:
> Nguyễn Thái Ngọc Duy <pclouds@gmail.com> wrote:
> > +test_expect_success FREEBSD 'Work around lazy mtime update' '
> > +	ls -ld . >/dev/null
> > +'
> 
> 	stat . >/dev/null

If there's some older FreeBSD w/o stat(1); "test -x ."
ought to work, too, and it's faster being a shell builtin.

I suspect some shell might be clever about optimizing away
a more-obvious "test -d .", so I choose "test -x ."

> would be more to the point of what is going on, here.   But I
> also wonder if untracked cache itself could/should be doing this
> internally.

Still wondering :>

> (I'm not familiar with that code, of course)
> 
> Thanks again for looking into this.

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Duy Nguyen]

On Sun, Jul 31, 2016 at 3:07 AM, Eric Wong <e@80x24.org> wrote:
>> would be more to the point of what is going on, here.   But I
>> also wonder if untracked cache itself could/should be doing this
>> internally.
>
> Still wondering :>

There's nothing we can do besides maybe run a cron job executing
'sync' every second or so. We need to force mtime to be written down
close to.. you know.. mtime. By the time git is executed, it's already
late. You can execute 'sync' inside git then wait a couple seconds..
but that's just stupid. And removing the racy check is even more
dangerous, now you can get false output.
-- 
Duy

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Torstem Bögershausen]

> Am 30.07.2016 um 15:20 schrieb Nguyễn Thái Ngọc Duy <pclouds@gmail.com>:
> 
> Let's start with the commit message of [1] from freebsd.git [2]
> 
>    Sync timestamp changes for inodes of special files to disk as late
>    as possible (when the inode is reclaimed).  Temporarily only do
>    this if option UFS_LAZYMOD configured and softupdates aren't
>    enabled.  UFS_LAZYMOD is intentionally left out of
>    /sys/conf/options.
> 
>    This is mainly to avoid almost useless disk i/o on battery powered
>    machines.  It's silly to write to disk (on the next sync or when
>    the inode becomes inactive) just because someone hit a key or
>    something wrote to the screen or /dev/null.
> 
>    PR:             5577 [3]
> 
> The short version of that, in the context of t7063, is that when a
> directory is updated, its mtime may be updated later, not
> immediately. This can be shown with a simple command sequence
> 
>    date; sleep 1; touch abc; rm abc; sleep 10; ls -lTd .
> 
> One would expect that the date shown in `ls` would be one second from
> `date`, but it's 10 seconds later. If we put another `ls -lTd .` in
> front of `sleep 10`, then the date of the last `ls` comes as
> expected. The first `ls` somehow forces mtime to be updated.
> 
> t7063 is really sensitive to directory mtime. When mtime is too "new",
> git code suspects racy timestamps and will not trigger the shortcut in
> untracked cache, in t7063.26 (or t7063.25 before this patch) and
> eventually be detected in t7063.28
> 
> We have two options thanks to this special FreeBSD feature:
> 
> 1) Stop supporting untracked cache on FreeBSD. Skip t7063 entirely
>   when running on FreeBSD
> 
> 2) Work around this problem (using the same 'ls' trick) and continue
>   to support untracked cache on FreeBSD
> 
> I initially wanted to go with 1) because I didn't know the exact
> nature of this feature and feared that it would make untracked cache
> work unreliably, using the cached version when it should not.
> 
> Since the behavior of this thing is clearer now. The picture is not
> that bad. If this indeed happens often, untracked cache would assume
> racy condition more often and _fall back_ to non-untracked cache code
> paths. Which means it may be less effective, but it will not show
> wrong things.
> 
> This patch goes with option 2.
> 
> PS. For those who want to look further in FreeBSD source code, this
> flag is now called IN_LAZYMOD. I can see it's effective in ext2 and
> ufs. zfs is questionable.
> 
> [1] 660e6408e6df99a20dacb070c5e7f9739efdf96d
> [2] git://github.com/freebsd/freebsd.git
> [3] https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=5577
> 
> Reported-by: Eric Wong <e@80x24.org>
> Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
> ---
> This is only of those commits that commit messages are more important
> than the patch itself. One of the good notes about directory mtime,
> if we start to use it in more places in git.
> 
> t/t7063-status-untracked-cache.sh | 4 ++++
> t/test-lib.sh                     | 6 ++++++
> 2 files changed, 10 insertions(+)
> 
> diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
> index a971884..08fc586 100755
> --- a/t/t7063-status-untracked-cache.sh
> +++ b/t/t7063-status-untracked-cache.sh
> @@ -419,6 +419,10 @@ test_expect_success 'create/modify files, some of which are gitignored' '
>    rm base
> '
> 
> +test_expect_success FREEBSD 'Work around lazy mtime update' '
> +    ls -ld . >/dev/null
> +'
> +

the term FREEBSD may be too generic to point out a single feature
in an OS distributution.
Following your investigations, it may even be possible that
other systems adapt this "feature"?

How about
LAZY_DIR_MTIME_UPDATE
(or similar)

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Duy Nguyen]

On Mon, Aug 1, 2016 at 3:37 AM, Torstem Bögershausen <tboegi@web.de> wrote:
> the term FREEBSD may be too generic to point out a single feature
> in an OS distributution.
> Following your investigations, it may even be possible that
> other systems adapt this "feature"?
>
> How about
> LAZY_DIR_MTIME_UPDATE
> (or similar)

This feature was added in 1998, so yes there's a chance it has spread
to a few fbsd derivatives (not sure if openbsd or netbsd is close
enough and they ever exchange changes). But I'd rather wait for the
second OS to expose the same feature before renaming it.
-- 
Duy

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Junio C Hamano]

Duy Nguyen <pclouds@gmail.com> writes:

> On Mon, Aug 1, 2016 at 3:37 AM, Torstem Bögershausen <tboegi@web.de> wrote:
>> the term FREEBSD may be too generic to point out a single feature
>> in an OS distributution.
>> Following your investigations, it may even be possible that
>> other systems adapt this "feature"?
>>
>> How about
>> LAZY_DIR_MTIME_UPDATE
>> (or similar)
>
> This feature was added in 1998, so yes there's a chance it has spread
> to a few fbsd derivatives (not sure if openbsd or netbsd is close
> enough and they ever exchange changes). But I'd rather wait for the
> second OS to expose the same feature before renaming it.

I think a name based on the observed behaviour ("feature") would be
more appropriate because I'd be more worried about us finding other
glitches we see (initially) only on FBSD.  People who need to adjust
tests that use the same FBSD prereq would have to wonder which
prereq-skip is due to which glitch.

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Duy Nguyen]

On Mon, Aug 01, 2016 at 02:04:44PM -0700, Junio C Hamano wrote:
> Duy Nguyen <pclouds@gmail.com> writes:
> 
> > On Mon, Aug 1, 2016 at 3:37 AM, Torstem Bögershausen <tboegi@web.de> wrote:
> >> the term FREEBSD may be too generic to point out a single feature
> >> in an OS distributution.
> >> Following your investigations, it may even be possible that
> >> other systems adapt this "feature"?
> >>
> >> How about
> >> LAZY_DIR_MTIME_UPDATE
> >> (or similar)
> >
> > This feature was added in 1998, so yes there's a chance it has spread
> > to a few fbsd derivatives (not sure if openbsd or netbsd is close
> > enough and they ever exchange changes). But I'd rather wait for the
> > second OS to expose the same feature before renaming it.
> 
> I think a name based on the observed behaviour ("feature") would be
> more appropriate because I'd be more worried about us finding other
> glitches we see (initially) only on FBSD.  People who need to adjust
> tests that use the same FBSD prereq would have to wonder which
> prereq-skip is due to which glitch.

OK how about this squashed in? The name was taken from fbsd definition
IN_LAZYMOD.

Off topic. Since I found this macro defined twice, in ext2 and ufs,
but not in zfs (found its source!), I assume zfs does not have this
particular feature (but I didn't test it). Untracked cache may be more
effecient there.

-- 8< --
diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index 08fc586..8bb048a 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -419,7 +419,7 @@ test_expect_success 'create/modify files, some of which are gitignored' '
 	rm base
 '
 
-test_expect_success FREEBSD 'Work around lazy mtime update' '
+test_expect_success LAZYMOD 'Work around lazy mtime update' '
 	ls -ld . >/dev/null
 '
 
diff --git a/t/test-lib.sh b/t/test-lib.sh
index 3c730a2..1fc5266 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -962,7 +962,7 @@ case $(uname -s) in
 	test_set_prereq GREP_STRIPS_CR
 	;;
 *FreeBSD*)
-	test_set_prereq FREEBSD
+	test_set_prereq LAZYMOD
 	test_set_prereq POSIXPERM
 	test_set_prereq BSLASHPSPEC
 	test_set_prereq EXECKEEPSPID
-- 8< --

--
Duy

Re: [PATCH] t7063: work around FreeBSD's lazy mtime update feature

[Junio C Hamano]

Duy Nguyen <pclouds@gmail.com> writes:

> OK how about this squashed in? The name was taken from fbsd definition
> IN_LAZYMOD.

I am sorry that I didn't spot this possiblity earlier, but do we
need anything conditional?  Either FREEBSD or LAZYMOD prerequisite
tells very little what the "Work around lazy mtime update" is and
where it triggers (I think the conclusion of your investigation was
that the timestamp on the containing directory, but that is ONLY
recorded in the log message, i.e. readers need to run 'git blame'
to find out).

It might be a better approach to have a helper function with
descriptive name and comment early in t7063, e.g.

	# On some filesystems (e.g. FreeBSD's ext2 and ufs) this
        # and that happens when we do blah, which forces the
        # untracked cache code to take the slow path.  A test
        # that wants to make sure the fast path works correctly
        # should call this helper to make mtime of the containing
        # directory in sync with the reality after doing blah and
        # before checking the fast path behaviour
	test_sync_directory_mtime () {
		ls -ld . >/dev/null
        }

and then call it at strategic places without any prerequisite.

The helper may turn out to be useful outside the context of 7063
later, at which time we can move it to test-lib-functions, but that
is a separate step.

> Off topic. Since I found this macro defined twice, in ext2 and ufs,
> but not in zfs (found its source!), I assume zfs does not have this
> particular feature (but I didn't test it). Untracked cache may be more
> effecient there.


> -- 8< --
> diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
> index 08fc586..8bb048a 100755
> --- a/t/t7063-status-untracked-cache.sh
> +++ b/t/t7063-status-untracked-cache.sh
> @@ -419,7 +419,7 @@ test_expect_success 'create/modify files, some of which are gitignored' '
>  	rm base
>  '
>  
> -test_expect_success FREEBSD 'Work around lazy mtime update' '
> +test_expect_success LAZYMOD 'Work around lazy mtime update' '
>  	ls -ld . >/dev/null
>  '
>  
> diff --git a/t/test-lib.sh b/t/test-lib.sh
> index 3c730a2..1fc5266 100644
> --- a/t/test-lib.sh
> +++ b/t/test-lib.sh
> @@ -962,7 +962,7 @@ case $(uname -s) in
>  	test_set_prereq GREP_STRIPS_CR
>  	;;
>  *FreeBSD*)
> -	test_set_prereq FREEBSD
> +	test_set_prereq LAZYMOD
>  	test_set_prereq POSIXPERM
>  	test_set_prereq BSLASHPSPEC
>  	test_set_prereq EXECKEEPSPID
> -- 8< --
>
> --
> Duy

[PATCH v2] t7063: work around FreeBSD's lazy mtime update feature

[Nguyễn Thái Ngọc Duy]

Let's start with the commit message of [1] from freebsd.git [2]

    Sync timestamp changes for inodes of special files to disk as late
    as possible (when the inode is reclaimed).  Temporarily only do
    this if option UFS_LAZYMOD configured and softupdates aren't
    enabled.  UFS_LAZYMOD is intentionally left out of
    /sys/conf/options.

    This is mainly to avoid almost useless disk i/o on battery powered
    machines.  It's silly to write to disk (on the next sync or when
    the inode becomes inactive) just because someone hit a key or
    something wrote to the screen or /dev/null.

    PR:             5577 [3]

The short version of that, in the context of t7063, is that when a
directory is updated, its mtime may be updated later, not
immediately. This can be shown with a simple command sequence

    date; sleep 1; touch abc; rm abc; sleep 10; ls -lTd .

One would expect that the date shown in `ls` would be one second from
`date`, but it's 10 seconds later. If we put another `ls -lTd .` in
front of `sleep 10`, then the date of the last `ls` comes as
expected. The first `ls` somehow forces mtime to be updated.

t7063 is really sensitive to directory mtime. When mtime is too "new",
git code suspects racy timestamps and will not trigger the shortcut in
untracked cache, in t7063.24 and eventually be detected in t7063.27

We have two options thanks to this special FreeBSD feature:

1) Stop supporting untracked cache on FreeBSD. Skip t7063 entirely
   when running on FreeBSD

2) Work around this problem (using the same 'ls' trick) and continue
   to support untracked cache on FreeBSD

I initially wanted to go with 1) because I didn't know the exact
nature of this feature and feared that it would make untracked cache
work unreliably, using the cached version when it should not.

Since the behavior of this thing is clearer now. The picture is not
that bad. If this indeed happens often, untracked cache would assume
racy condition more often and _fall back_ to non-untracked cache code
paths. Which means it may be less effective, but it will not show
wrong things.

This patch goes with option 2.

PS. For those who want to look further in FreeBSD source code, this
flag is now called IN_LAZYMOD. I can see it's effective in ext2 and
ufs. zfs is not affected.

[1] 660e6408e6df99a20dacb070c5e7f9739efdf96d
[2] git://github.com/freebsd/freebsd.git
[3] https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=5577

Reported-by: Eric Wong <e@80x24.org>
Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
---
 v2 goes with Junio's suggestion (good one!). And since there is an
 intention to reuse this new function, I make sure all directories are
 stat'd to pin down their mtime.

 t/t7063-status-untracked-cache.sh | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)

diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index a971884..7dd4de0 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -4,6 +4,16 @@ test_description='test untracked cache'
 
 . ./test-lib.sh
 
+# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
+# happens when we do blah, which forces the untracked cache code to
+# take the slow path.  A test that wants to make sure the fast path
+# works correctly should call this helper to make mtime of the
+# containing directory in sync with the reality after doing blah and
+# before checking the fast path behaviour
+sync_mtime () {
+	find . -type d -exec ls -ld {} \; >/dev/null
+}
+
 avoid_racy() {
 	sleep 1
 }
@@ -416,7 +426,8 @@ test_expect_success 'create/modify files, some of which are gitignored' '
 	echo four >done/four && # four is gitignored at a higher level
 	echo five >done/five && # five is not gitignored
 	echo test >base && #we need to ensure that the root dir is touched
-	rm base
+	rm base &&
+	sync_mtime
 '
 
 test_expect_success 'test sparse status with untracked cache' '
-- 
2.9.1.566.gbd532d4

Re: [PATCH v2] t7063: work around FreeBSD's lazy mtime update feature

[Junio C Hamano]

Nguyễn Thái Ngọc Duy  <pclouds@gmail.com> writes:

>  v2 goes with Junio's suggestion (good one!).

Ehh, have you even read what you copied and pasted?  "this and that"
and "blah" are meant to be placeholders for you to fill in.

I am not sure if "-exec ls -ld" is a good idea.  Doesn't "find" by
itself does enough lstat(2) call to work already?  Even if it were
necessary to trigger a separate stat(2) call, wouldn't "-ls" be
sufficient?

> +# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
> +# happens when we do blah, which forces the untracked cache code to
> +# take the slow path.  A test that wants to make sure the fast path
> +# works correctly should call this helper to make mtime of the
> +# containing directory in sync with the reality after doing blah and
> +# before checking the fast path behaviour
> +sync_mtime () {
> +	find . -type d -exec ls -ld {} \; >/dev/null
> +}
> +
>  avoid_racy() {
>  	sleep 1
>  }
> @@ -416,7 +426,8 @@ test_expect_success 'create/modify files, some of which are gitignored' '
>  	echo four >done/four && # four is gitignored at a higher level
>  	echo five >done/five && # five is not gitignored
>  	echo test >base && #we need to ensure that the root dir is touched
> -	rm base
> +	rm base &&
> +	sync_mtime
>  '
>  
>  test_expect_success 'test sparse status with untracked cache' '

Re: [PATCH v2] t7063: work around FreeBSD's lazy mtime update feature

[Duy Nguyen]

On Wed, Aug 3, 2016 at 6:16 PM, Junio C Hamano <gitster@pobox.com> wrote:
> Nguyễn Thái Ngọc Duy  <pclouds@gmail.com> writes:
>
>>  v2 goes with Junio's suggestion (good one!).
>
> Ehh, have you even read what you copied and pasted?  "this and that"
> and "blah" are meant to be placeholders for you to fill in.

I did. But after a bit of consideration, I think the confusion caused
by "this and that" would force the reader to blame and read the entire
commit message.

> I am not sure if "-exec ls -ld" is a good idea.  Doesn't "find" by
> itself does enough lstat(2) call to work already?

Hmm.. because in some cases we could have dtype from readdir()?

> Even if it were
> necessary to trigger a separate stat(2) call, wouldn't "-ls" be
> sufficient?

Yep. Let me run some tests before sending v3.
-- 
Duy

[PATCH v3] t7063: work around FreeBSD's lazy mtime update feature

[Nguyễn Thái Ngọc Duy]

Let's start with the commit message of [1] from freebsd.git [2]

    Sync timestamp changes for inodes of special files to disk as late
    as possible (when the inode is reclaimed).  Temporarily only do
    this if option UFS_LAZYMOD configured and softupdates aren't
    enabled.  UFS_LAZYMOD is intentionally left out of
    /sys/conf/options.

    This is mainly to avoid almost useless disk i/o on battery powered
    machines.  It's silly to write to disk (on the next sync or when
    the inode becomes inactive) just because someone hit a key or
    something wrote to the screen or /dev/null.

    PR:             5577 [3]

The short version of that, in the context of t7063, is that when a
directory is updated, its mtime may be updated later, not
immediately. This can be shown with a simple command sequence

    date; sleep 1; touch abc; rm abc; sleep 10; ls -lTd .

One would expect that the date shown in `ls` would be one second from
`date`, but it's 10 seconds later. If we put another `ls -lTd .` in
front of `sleep 10`, then the date of the last `ls` comes as
expected. The first `ls` somehow forces mtime to be updated.

t7063 is really sensitive to directory mtime. When mtime is too "new",
git code suspects racy timestamps and will not trigger the shortcut in
untracked cache, in t7063.24 and eventually be detected in t7063.27

We have two options thanks to this special FreeBSD feature:

1) Stop supporting untracked cache on FreeBSD. Skip t7063 entirely
   when running on FreeBSD

2) Work around this problem (using the same 'ls' trick) and continue
   to support untracked cache on FreeBSD

I initially wanted to go with 1) because I didn't know the exact
nature of this feature and feared that it would make untracked cache
work unreliably, using the cached version when it should not.

Since the behavior of this thing is clearer now. The picture is not
that bad. If this indeed happens often, untracked cache would assume
racy condition more often and _fall back_ to non-untracked cache code
paths. Which means it may be less effective, but it will not show
wrong things.

This patch goes with option 2.

PS. For those who want to look further in FreeBSD source code, this
flag is now called IN_LAZYMOD. I can see it's effective in ext2 and
ufs. zfs is not affected.

[1] 660e6408e6df99a20dacb070c5e7f9739efdf96d
[2] git://github.com/freebsd/freebsd.git
[3] https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=5577

Reported-by: Eric Wong <e@80x24.org>
Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
---
 v3 differs from v2 in one line

    --- a/t/t7063-status-untracked-cache.sh
    +++ b/t/t7063-status-untracked-cache.sh
    @@ -11,7 +11,7 @@ test_description='test untracked cache'
     # containing directory in sync with the reality after doing blah and
     # before checking the fast path behaviour
     sync_mtime () {
    -	find . -type d -exec ls -ld {} \; >/dev/null
    +	find . -type d -ls >/dev/null
     }
 
 avoid_racy() {
 t/t7063-status-untracked-cache.sh | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)

diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index a971884..d31d080 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -4,6 +4,16 @@ test_description='test untracked cache'
 
 . ./test-lib.sh
 
+# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
+# happens when we do blah, which forces the untracked cache code to
+# take the slow path.  A test that wants to make sure the fast path
+# works correctly should call this helper to make mtime of the
+# containing directory in sync with the reality after doing blah and
+# before checking the fast path behaviour
+sync_mtime () {
+	find . -type d -ls >/dev/null
+}
+
 avoid_racy() {
 	sleep 1
 }
@@ -416,7 +426,8 @@ test_expect_success 'create/modify files, some of which are gitignored' '
 	echo four >done/four && # four is gitignored at a higher level
 	echo five >done/five && # five is not gitignored
 	echo test >base && #we need to ensure that the root dir is touched
-	rm base
+	rm base &&
+	sync_mtime
 '
 
 test_expect_success 'test sparse status with untracked cache' '
-- 
2.9.1.566.gbd532d4

Re: [PATCH v3] t7063: work around FreeBSD's lazy mtime update feature

[Junio C Hamano]

On Wed, Aug 3, 2016 at 10:45 AM, Nguyễn Thái Ngọc Duy <pclouds@gmail.com> wrote:
>  v3 differs from v2 in one line
>
>     --- a/t/t7063-status-untracked-cache.sh
>     +++ b/t/t7063-status-untracked-cache.sh
>     @@ -11,7 +11,7 @@ test_description='test untracked cache'
>      # containing directory in sync with the reality after doing blah and
>      # before checking the fast path behaviour
>      sync_mtime () {
>     -   find . -type d -exec ls -ld {} \; >/dev/null
>     +   find . -type d -ls >/dev/null
>      }

"this and that" and "blah" are still there.

If you mean to tell the user "I won't describe it in detail, if you
really want to know,
go run blame yourself", spell it out like so. I was hoping that you
can summarize
in-line there to help the readers here.

> +# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
> +# happens when we do blah, which forces the untracked cache code to
> +# take the slow path.  A test that wants to make sure the fast path
> +# works correctly should call this helper to make mtime of the
> +# containing directory in sync with the reality after doing blah and
> +# before checking the fast path behaviour
> +sync_mtime () {
> +       find . -type d -ls >/dev/null
> +}
> +
>  avoid_racy() {
>         sleep 1
>  }
> @@ -416,7 +426,8 @@ test_expect_success 'create/modify files, some of which are gitignored' '
>         echo four >done/four && # four is gitignored at a higher level
>         echo five >done/five && # five is not gitignored
>         echo test >base && #we need to ensure that the root dir is touched
> -       rm base
> +       rm base &&
> +       sync_mtime
>  '
>
>  test_expect_success 'test sparse status with untracked cache' '
> --
> 2.9.1.566.gbd532d4
>

Re: [PATCH v3] t7063: work around FreeBSD's lazy mtime update feature

[Junio C Hamano]

Junio C Hamano <gitster@pobox.com> writes:

> If you mean to tell the user "I won't describe it in detail, if you
> really want to know,
> go run blame yourself", spell it out like so. I was hoping that you
> can summarize
> in-line there to help the readers here.

Here is a proposed fixup.

 t/t7063-status-untracked-cache.sh | 16 ++++++++++------
 1 file changed, 10 insertions(+), 6 deletions(-)

diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
index d31d080..e0a8228 100755
--- a/t/t7063-status-untracked-cache.sh
+++ b/t/t7063-status-untracked-cache.sh
@@ -4,12 +4,16 @@ test_description='test untracked cache'
 
 . ./test-lib.sh
 
-# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
-# happens when we do blah, which forces the untracked cache code to
-# take the slow path.  A test that wants to make sure the fast path
-# works correctly should call this helper to make mtime of the
-# containing directory in sync with the reality after doing blah and
-# before checking the fast path behaviour
+# On some filesystems (e.g. FreeBSD's ext2 and ufs) directory mtime
+# is updated lazily after contents in the directory changes, which
+# forces the untracked cache code to take the slow path.  A test
+# that wants to make sure that the fast path works correctly should
+# call this helper to make mtime of the containing directory in sync
+# with the reality before checking the fast path behaviour.
+#
+# See <20160803174522.5571-1-pclouds@gmail.com> if you want to know
+# more.
+
 sync_mtime () {
 	find . -type d -ls >/dev/null
 }

Re: [PATCH v3] t7063: work around FreeBSD's lazy mtime update feature

[Duy Nguyen]

On Wed, Aug 3, 2016 at 9:07 PM, Junio C Hamano <gitster@pobox.com> wrote:
> Junio C Hamano <gitster@pobox.com> writes:
>
>> If you mean to tell the user "I won't describe it in detail, if you
>> really want to know,
>> go run blame yourself", spell it out like so. I was hoping that you
>> can summarize
>> in-line there to help the readers here.
>
> Here is a proposed fixup.

Great! Sorry I only have one or two hours these days and could not
propose something else quicker.

>  t/t7063-status-untracked-cache.sh | 16 ++++++++++------
>  1 file changed, 10 insertions(+), 6 deletions(-)
>
> diff --git a/t/t7063-status-untracked-cache.sh b/t/t7063-status-untracked-cache.sh
> index d31d080..e0a8228 100755
> --- a/t/t7063-status-untracked-cache.sh
> +++ b/t/t7063-status-untracked-cache.sh
> @@ -4,12 +4,16 @@ test_description='test untracked cache'
>
>  . ./test-lib.sh
>
> -# On some filesystems (e.g. FreeBSD's ext2 and ufs) this and that
> -# happens when we do blah, which forces the untracked cache code to
> -# take the slow path.  A test that wants to make sure the fast path
> -# works correctly should call this helper to make mtime of the
> -# containing directory in sync with the reality after doing blah and
> -# before checking the fast path behaviour
> +# On some filesystems (e.g. FreeBSD's ext2 and ufs) directory mtime
> +# is updated lazily after contents in the directory changes, which
> +# forces the untracked cache code to take the slow path.  A test
> +# that wants to make sure that the fast path works correctly should
> +# call this helper to make mtime of the containing directory in sync
> +# with the reality before checking the fast path behaviour.
> +#
> +# See <20160803174522.5571-1-pclouds@gmail.com> if you want to know
> +# more.
> +
>  sync_mtime () {
>         find . -type d -ls >/dev/null
>  }



-- 
Duy