Re: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-09-06 Thread Stefan Beller 
> > Ben, do you have an idea?
> >
>
> I'll take a look as soon as I can (and at the other fsmonitor test issue Ævar 
> sent email about) but it may be a few days before I get a chance.
>
> I haven't had a chance to look into this yet but here are a couple of SWAG's 
> I'd start with:
>

> is it possible that "git mv" is triggering it early, making a change, and 
> then updating the index with stale fsmonitor data?

This is exactly what is happening. Thanks for describing the situation
precisely.

> I wonder if there is a missing call to mark_fsmonitor_invalid() in the "git 
> mv" codepath somewhere.
>
> refresh_fsmonitor() only runs once per git command

Just naively adding mark_fsmonitor_invalid doesn't work, as then
we have a sequence of

fsmonitor process '/u/git/t/t7519/fsmonitor-all' returned success
mark_fsmonitor_clean '.gitmodules'
mark_fsmonitor_invalid '.gitmodules'
write fsmonitor extension successful

and the marking invalid doesn't seem to override the first
mark as valid ?

>
> Sorry, I'll look as soon as I can.
>
> Ben

Thanks!
Stefan

RE: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-09-06 Thread Ben Peart 
> -Original Message-
> From: Stefan Beller 
> Sent: Thursday, September 6, 2018 12:57 PM
> To: Ævar Arnfjörð Bjarmason 
> Cc: Junio C Hamano ; git ; Ben
> Peart 
> Subject: Re: sb/submodule-move-nested breaks t7411 under
> GIT_FSMONITOR_TEST
> 
> > > Will debug further.
> >
> > I spotted this again after testing the split index (see
> >
> https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fpublic-
> inbox.org%2Fgit%2F87va7ireuu.fsf%40evledraar.gmail.com%2Fdata=0
> 2%7C01%7CBen.Peart%40microsoft.com%7C27c901f198a24e5a045a08d6141
> 9ce42%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636718498401
> 788697sdata=JfavHtKafiJRAVnvMXU3nw1RI27G4OFxs3Ymt7STbvM%3
> Dreserved=0) and
> > was testing the fsmonitor test mode as well.
> >
> > So gentle *poke*: Did you get anywhere with debugging this? It's still
> > failing on "master" now.
> 
> I started looking into this again, help would be appreciated, as I do not
> quite understand the fsmonitor part.
> 
> The error is in the setup, where we have "git mv a b"
> 
> GIT_TRACE_FSMONITOR=1 GIT_TRACE=1
> GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all
> ./t7411-submodule-config.sh -d -i -v -x
> ++ git mv a b
> trace: built-in: git mv a b
> read fsmonitor extension successful
> add fsmonitor
> refresh fsmonitor
> trace: run_command: cd '/u/git/t/trash
> directory.t7411-submodule-config/super'; /u/git/t/t7519/fsmonitor-all
> 1 1536252819824793728
> fsmonitor process '/u/git/t/t7519/fsmonitor-all' returned success
> mark_fsmonitor_clean '.gitmodules'
> write fsmonitor extension successful
> 
> or with more trace_printfs littered through the code
> (https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub
> .com%2Fstefanbeller%2Fgit%2Ftree%2Fsubmodule_fsmoitor_debugd
> ata=02%7C01%7CBen.Peart%40microsoft.com%7C27c901f198a24e5a045a08
> d61419ce42%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C6367184
> 98401788697sdata=poAUFlVDkoNP56t1hmdxHHyChrH05cut1iSVt70yJ
> eo%3Dreserved=0)
> 
> trace: built-in: git mv a b
> read fsmonitor extension successful
> add fsmonitor
> refresh fsmonitor
> trace: run_command: cd '/u/git/t/trash
> directory.t7411-submodule-config/super'; /u/git/t/t7519/fsmonitor-all
> 1 1536252497951329341
> fsmonitor process '/u/git/t/t7519/fsmonitor-all' returned success
> need to stage .gitmodules
> calling add_file_to_index
> 
> 
> I suspect that the FSMONITOR API is handled wrongly by the part of git-mv
> that writes out the .gitmodules file (if needed) and the .git/index (as 
> needed).
> 
> Ben, do you have an idea?
> 

I'll take a look as soon as I can (and at the other fsmonitor test issue Ævar 
sent email about) but it may be a few days before I get a chance.

I haven't had a chance to look into this yet but here are a couple of SWAG's 
I'd start with:

I wonder if there is a missing call to mark_fsmonitor_invalid() in the "git mv" 
codepath somewhere.

refresh_fsmonitor() only runs once per git command - is it possible that "git 
mv" is triggering it early, making a change, and then updating the index with 
stale fsmonitor data?

Sorry, I'll look as soon as I can.

Ben

> Thanks,
> Stefan

Re: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-09-06 Thread Stefan Beller 
> > Will debug further.
>
> I spotted this again after testing the split index (see
> https://public-inbox.org/git/87va7ireuu@evledraar.gmail.com/) and
> was testing the fsmonitor test mode as well.
>
> So gentle *poke*: Did you get anywhere with debugging this? It's still
> failing on "master" now.

I started looking into this again, help would be appreciated, as I do not
quite understand the fsmonitor part.

The error is in the setup, where we have "git mv a b"

GIT_TRACE_FSMONITOR=1 GIT_TRACE=1
GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all
./t7411-submodule-config.sh -d -i -v -x
++ git mv a b
trace: built-in: git mv a b
read fsmonitor extension successful
add fsmonitor
refresh fsmonitor
trace: run_command: cd '/u/git/t/trash
directory.t7411-submodule-config/super'; /u/git/t/t7519/fsmonitor-all
1 1536252819824793728
fsmonitor process '/u/git/t/t7519/fsmonitor-all' returned success
mark_fsmonitor_clean '.gitmodules'
write fsmonitor extension successful

or with more trace_printfs littered through the code
(https://github.com/stefanbeller/git/tree/submodule_fsmoitor_debug)

trace: built-in: git mv a b
read fsmonitor extension successful
add fsmonitor
refresh fsmonitor
trace: run_command: cd '/u/git/t/trash
directory.t7411-submodule-config/super'; /u/git/t/t7519/fsmonitor-all
1 1536252497951329341
fsmonitor process '/u/git/t/t7519/fsmonitor-all' returned success
need to stage .gitmodules
calling add_file_to_index


I suspect that the FSMONITOR API is handled wrongly by the part of git-mv
that writes out the .gitmodules file (if needed) and the .git/index (as needed).

Ben, do you have an idea?

Thanks,
Stefan

Re: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-09-06 Thread Ævar Arnfjörð Bjarmason 


On Fri, May 25 2018, Stefan Beller wrote:

> On Fri, May 25, 2018 at 5:28 AM, Ævar Arnfjörð Bjarmason
>  wrote:
>>
>> On Thu, May 17 2018, Junio C Hamano wrote:
>>
>>> * sb/submodule-move-nested (2018-03-29) 6 commits
>>>   (merged to 'next' on 2018-04-25 at 86b177433a)
>>>  + submodule: fixup nested submodules after moving the submodule
>>>  + submodule-config: remove submodule_from_cache
>>>  + submodule-config: add repository argument to submodule_from_{name, path}
>>>  + submodule-config: allow submodule_free to handle arbitrary repositories
>>>  + grep: remove "repo" arg from non-supporting funcs
>>>  + submodule.h: drop declaration of connect_work_tree_and_git_dir
>>>
>>>  Moving a submodule that itself has submodule in it with "git mv"
>>>  forgot to make necessary adjustment to the nested sub-submodules;
>>>  now the codepath learned to recurse into the submodules.
>>
>> I didn't spot this earlier because I don't test this a lot, but I've
>> bisected the following breakage down to da62f786d2 ("submodule: fixup
>> nested submodules after moving the submodule", 2018-03-28) (and manually
>> confirmed by reverting). On Linux both Debian & CentOS I get tests 3 and
>> 4 failing with:
>>
>>  GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all ./t7411-submodule-config.sh
>>
>> -v -x output follows:
>>
>> expecting success:
>> mkdir submodule &&
>> (cd submodule &&
>> git init &&
>> echo a >a &&
>> git add . &&
>> git commit -ma
>> ) &&
>> mkdir super &&
>> (cd super &&
>> git init &&
>> git submodule add ../submodule &&
>> git submodule add ../submodule a &&
>> git commit -m "add as submodule and as a" &&
>> git mv a b &&
>> git commit -m "move a to b"
>> )
>
> when you add a test_pause here and dump the
> state of the setup, then it can be observed that when the fsmonitor is active
> the last commit is different; without fsmonitor the moved gitlink and the 
> change
> to the .gitmodules file is part of the commit, i.e.
>
> $ git -C super show
> commit d3d90b70a01bd17d026f75a803c8b65f5903a7c0 (HEAD -> master)
> Author: A U Thor 
> Date:   Fri May 25 19:21:58 2018 +
>
> move a to b
>
> diff --git a/.gitmodules b/.gitmodules
> index 3f4d474..6149210 100644
> --- a/.gitmodules
> +++ b/.gitmodules
> @@ -2,5 +2,5 @@
>   path = submodule
>   url = ../submodule
>  [submodule "a"]
> - path = a
> + path = b
>   url = ../submodule
> diff --git a/a b/b
> similarity index 100%
> rename from a
> rename to b
> When running with the fsmonitor:
>
> $ git -C super show
> commit 57022a92acf46f303498c045440ec099cbc35a2d (HEAD -> master)
> Author: A U Thor 
> Date:   Fri May 25 19:22:52 2018 +
>
> move a to b
>
> diff --git a/a b/b
> similarity index 100%
> rename from a
> rename to b
> $ git -C super diff
> diff --git a/.gitmodules b/.gitmodules
> index 3f4d474..6149210 100644
> --- a/.gitmodules
> +++ b/.gitmodules
> @@ -2,5 +2,5 @@
>   path = submodule
>   url = ../submodule
>  [submodule "a"]
> - path = a
> + path = b
>   url = ../submodule
>
> This hints at a problem with git commit;
>
> I tried adding test_tick, to unconfuse the fsmonitor, but that doesn't help,
> digging further, the problem is in the git mv command, which fails to
> add the change in
> .gitmodules to the index.
>
> Adding the verbose flag to stage_updated_gitmodules() that is called by
> git-mv very late in the game, such that
>
> void stage_updated_gitmodules(struct index_state *istate)
> {
> trace_printf("staging .gitmodules files");
> if (add_file_to_index(istate, GITMODULES_FILE, ADD_CACHE_VERBOSE))
> die(_("staging updated .gitmodules failed"));
> }
>
> We would get a message if the .gitmodules file is staged correctly, as
> add_file_to_index() that calls add_to_index that would print
>
> if (verbose && !was_same)
> printf("add '%s'\n", path);
>
> I could not see that message, so I suspect, that there is something
> racy.
>
> Will debug further.

I spotted this again after testing the split index (see
https://public-inbox.org/git/87va7ireuu@evledraar.gmail.com/) and
was testing the fsmonitor test mode as well.

So gentle *poke*: Did you get anywhere with debugging this? It's still
failing on "master" now.

Re: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-05-25 Thread Stefan Beller 
On Fri, May 25, 2018 at 5:28 AM, Ævar Arnfjörð Bjarmason
 wrote:
>
> On Thu, May 17 2018, Junio C Hamano wrote:
>
>> * sb/submodule-move-nested (2018-03-29) 6 commits
>>   (merged to 'next' on 2018-04-25 at 86b177433a)
>>  + submodule: fixup nested submodules after moving the submodule
>>  + submodule-config: remove submodule_from_cache
>>  + submodule-config: add repository argument to submodule_from_{name, path}
>>  + submodule-config: allow submodule_free to handle arbitrary repositories
>>  + grep: remove "repo" arg from non-supporting funcs
>>  + submodule.h: drop declaration of connect_work_tree_and_git_dir
>>
>>  Moving a submodule that itself has submodule in it with "git mv"
>>  forgot to make necessary adjustment to the nested sub-submodules;
>>  now the codepath learned to recurse into the submodules.
>
> I didn't spot this earlier because I don't test this a lot, but I've
> bisected the following breakage down to da62f786d2 ("submodule: fixup
> nested submodules after moving the submodule", 2018-03-28) (and manually
> confirmed by reverting). On Linux both Debian & CentOS I get tests 3 and
> 4 failing with:
>
>  GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all ./t7411-submodule-config.sh
>
> -v -x output follows:
>
> expecting success:
> mkdir submodule &&
> (cd submodule &&
> git init &&
> echo a >a &&
> git add . &&
> git commit -ma
> ) &&
> mkdir super &&
> (cd super &&
> git init &&
> git submodule add ../submodule &&
> git submodule add ../submodule a &&
> git commit -m "add as submodule and as a" &&
> git mv a b &&
> git commit -m "move a to b"
> )

when you add a test_pause here and dump the
state of the setup, then it can be observed that when the fsmonitor is active
the last commit is different; without fsmonitor the moved gitlink and the change
to the .gitmodules file is part of the commit, i.e.

$ git -C super show
commit d3d90b70a01bd17d026f75a803c8b65f5903a7c0 (HEAD -> master)
Author: A U Thor 
Date:   Fri May 25 19:21:58 2018 +

move a to b

diff --git a/.gitmodules b/.gitmodules
index 3f4d474..6149210 100644
--- a/.gitmodules
+++ b/.gitmodules
@@ -2,5 +2,5 @@
  path = submodule
  url = ../submodule
 [submodule "a"]
- path = a
+ path = b
  url = ../submodule
diff --git a/a b/b
similarity index 100%
rename from a
rename to b
When running with the fsmonitor:

$ git -C super show
commit 57022a92acf46f303498c045440ec099cbc35a2d (HEAD -> master)
Author: A U Thor 
Date:   Fri May 25 19:22:52 2018 +

move a to b

diff --git a/a b/b
similarity index 100%
rename from a
rename to b
$ git -C super diff
diff --git a/.gitmodules b/.gitmodules
index 3f4d474..6149210 100644
--- a/.gitmodules
+++ b/.gitmodules
@@ -2,5 +2,5 @@
  path = submodule
  url = ../submodule
 [submodule "a"]
- path = a
+ path = b
  url = ../submodule

This hints at a problem with git commit;

I tried adding test_tick, to unconfuse the fsmonitor, but that doesn't help,
digging further, the problem is in the git mv command, which fails to
add the change in
.gitmodules to the index.

Adding the verbose flag to stage_updated_gitmodules() that is called by
git-mv very late in the game, such that

void stage_updated_gitmodules(struct index_state *istate)
{
trace_printf("staging .gitmodules files");
if (add_file_to_index(istate, GITMODULES_FILE, ADD_CACHE_VERBOSE))
die(_("staging updated .gitmodules failed"));
}

We would get a message if the .gitmodules file is staged correctly, as
add_file_to_index() that calls add_to_index that would print

if (verbose && !was_same)
printf("add '%s'\n", path);

I could not see that message, so I suspect, that there is something
racy.

Will debug further.

Re: sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-05-25 Thread Stefan Beller 
Hi Ævar,

On Fri, May 25, 2018 at 5:28 AM, Ævar Arnfjörð Bjarmason
 wrote:
>
> On Thu, May 17 2018, Junio C Hamano wrote:
>
>> * sb/submodule-move-nested (2018-03-29) 6 commits
>>   (merged to 'next' on 2018-04-25 at 86b177433a)
>>  + submodule: fixup nested submodules after moving the submodule
>>  + submodule-config: remove submodule_from_cache
>>  + submodule-config: add repository argument to submodule_from_{name, path}
>>  + submodule-config: allow submodule_free to handle arbitrary repositories
>>  + grep: remove "repo" arg from non-supporting funcs
>>  + submodule.h: drop declaration of connect_work_tree_and_git_dir
>>
>>  Moving a submodule that itself has submodule in it with "git mv"
>>  forgot to make necessary adjustment to the nested sub-submodules;
>>  now the codepath learned to recurse into the submodules.
>
> I didn't spot this earlier because I don't test this a lot, but I've
> bisected the following breakage down to da62f786d2 ("submodule: fixup
> nested submodules after moving the submodule", 2018-03-28) (and manually
> confirmed by reverting). On Linux both Debian & CentOS I get tests 3 and
> 4 failing with:
>
>  GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all ./t7411-submodule-config.sh

I can reproduce this. I'll look into it.

sb/submodule-move-nested breaks t7411 under GIT_FSMONITOR_TEST

2018-05-25 Thread Ævar Arnfjörð Bjarmason 

On Thu, May 17 2018, Junio C Hamano wrote:

> * sb/submodule-move-nested (2018-03-29) 6 commits
>   (merged to 'next' on 2018-04-25 at 86b177433a)
>  + submodule: fixup nested submodules after moving the submodule
>  + submodule-config: remove submodule_from_cache
>  + submodule-config: add repository argument to submodule_from_{name, path}
>  + submodule-config: allow submodule_free to handle arbitrary repositories
>  + grep: remove "repo" arg from non-supporting funcs
>  + submodule.h: drop declaration of connect_work_tree_and_git_dir
>
>  Moving a submodule that itself has submodule in it with "git mv"
>  forgot to make necessary adjustment to the nested sub-submodules;
>  now the codepath learned to recurse into the submodules.

I didn't spot this earlier because I don't test this a lot, but I've
bisected the following breakage down to da62f786d2 ("submodule: fixup
nested submodules after moving the submodule", 2018-03-28) (and manually
confirmed by reverting). On Linux both Debian & CentOS I get tests 3 and
4 failing with:

 GIT_FSMONITOR_TEST=$PWD/t7519/fsmonitor-all ./t7411-submodule-config.sh

-v -x output follows:

expecting success: 
mkdir submodule &&
(cd submodule &&
git init &&
echo a >a &&
git add . &&
git commit -ma
) &&
mkdir super &&
(cd super &&
git init &&
git submodule add ../submodule &&
git submodule add ../submodule a &&
git commit -m "add as submodule and as a" &&
git mv a b &&
git commit -m "move a to b"
)

+ mkdir submodule
+ cd submodule
+ git init
Initialized empty Git repository in /home/avar/g/git/t/trash 
directory.t7411-submodule-config/submodule/.git/
+ echo a
+ git add .
+ git commit -ma
[master (root-commit) 27e9f0e] a
 Author: A U Thor 
 1 file changed, 1 insertion(+)
 create mode 100644 a
+ mkdir super
+ cd super
+ git init
Initialized empty Git repository in /home/avar/g/git/t/trash 
directory.t7411-submodule-config/super/.git/
+ git submodule add ../submodule
Cloning into '/home/avar/g/git/t/trash 
directory.t7411-submodule-config/super/submodule'...
done.
+ git submodule add ../submodule a
Cloning into '/home/avar/g/git/t/trash 
directory.t7411-submodule-config/super/a'...
done.
+ git commit -m add as submodule and as a
[master (root-commit) 5a1dac1] add as submodule and as a
 Author: A U Thor 
 3 files changed, 8 insertions(+)
 create mode 100644 .gitmodules
 create mode 16 a
 create mode 16 submodule
+ git mv a b
+ git commit -m move a to b
[master ab1e9c7] move a to b
 Author: A U Thor 
 1 file changed, 0 insertions(+), 0 deletions(-)
 rename a => b (100%)
ok 1 - submodule config cache setup

expecting success: 
test_when_finished "rm -rf repo" &&
test_create_repo repo &&
cat >repo/.gitmodules <<-\EOF &&
[submodule "s"]
path
ignore
EOF
(
cd repo &&
test_must_fail test-submodule-config "" s 2>actual &&
test_i18ngrep "bad config" actual
)

+ test_when_finished rm -rf repo
+ test 0 = 0
+ test_cleanup={ rm -rf repo
} && (exit "$eval_ret"); eval_ret=$?; :
+ test_create_repo repo
+ test 1 = 1
+ repo=repo
+ mkdir -p repo
+ cd repo
+ /home/avar/g/git/t/../git-init --template=/home/avar/g/git/t/../templates/blt/
Initialized empty Git repository in /home/avar/g/git/t/trash 
directory.t7411-submodule-config/repo/.git/
+ mv .git/hooks .git/hooks-disabled
+ cat
+ cd repo
+ test_must_fail test-submodule-config  s
+ test_i18ngrep bad config actual
+ test -n 
+ test x! = xbad config
+ grep bad config actual
fatal: bad config line 2 in file /home/avar/g/git/t/trash 
directory.t7411-submodule-config/repo/.gitmodules
+ rm -rf repo
+ exit 0
+ eval_ret=0
+ :
ok 2 - configuration parsing with error

expecting success: 
(cd super &&
test-submodule-config \
HEAD^ a \
HEAD b \
HEAD^ submodule \
HEAD submodule \
>actual &&
test_cmp expect actual
)

+ cd super
+ test-submodule-config HEAD^ a HEAD b HEAD^ submodule HEAD submodule
warning: ab1e9c76c1e6a15df51b20e75552ec5ad00708ac:.gitmodules, multiple 
configurations found for 'submodule.submodule.path'. Skipping second one!
warning: ab1e9c76c1e6a15df51b20e75552ec5ad00708ac:.gitmodules, multiple 
configurations found for 'submodule.submodule.url'. Skipping second one!
warning: ab1e9c76c1e6a15df51b20e75552ec5ad00708ac:.gitmodules, multiple 
configurations found for 'submodule.a.path'. Skipping second one!
warning: ab1e9c76c1e6a15df51b20e75552ec5ad00708ac:.gitmodules, multiple 
configurations found for 'submodule.a.url'. Skipping second one!