* [PATCH 0/4] fsmonitor fixes @ 2017-10-20 1:11 Alex Vandiver 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver 2017-10-20 13:17 ` [PATCH 0/4] fsmonitor fixes Johannes Schindelin 0 siblings, 2 replies; 21+ messages in thread From: Alex Vandiver @ 2017-10-20 1:11 UTC (permalink / raw) To: git; +Cc: Ben Peart A few fixes found from playing around with the fsmonitor branch in next. - Alex ^ permalink raw reply [flat|nested] 21+ messages in thread
* [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD 2017-10-20 1:11 [PATCH 0/4] fsmonitor fixes Alex Vandiver @ 2017-10-20 1:11 ` Alex Vandiver 2017-10-20 1:11 ` [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman Alex Vandiver ` (3 more replies) 2017-10-20 13:17 ` [PATCH 0/4] fsmonitor fixes Johannes Schindelin 1 sibling, 4 replies; 21+ messages in thread From: Alex Vandiver @ 2017-10-20 1:11 UTC (permalink / raw) To: git; +Cc: Ben Peart, Alex Vandiver Signed-off-by: Alex Vandiver <alexmv@dropbox.com> --- t/t7519/fsmonitor-watchman | 3 ++- templates/hooks--fsmonitor-watchman.sample | 3 ++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman index a3e30bf54..377edc7be 100755 --- a/t/t7519/fsmonitor-watchman +++ b/t/t7519/fsmonitor-watchman @@ -41,7 +41,8 @@ if ($system =~ m/^MSYS_NT/ || $system =~ m/^MINGW/) { $git_work_tree =~ s/[\r\n]+//g; $git_work_tree =~ s,\\,/,g; } else { - $git_work_tree = $ENV{'PWD'}; + $git_work_tree = `git rev-parse --show-toplevel`; + chomp $git_work_tree; } my $retry = 1; diff --git a/templates/hooks--fsmonitor-watchman.sample b/templates/hooks--fsmonitor-watchman.sample index 9eba8a740..7df590d29 100755 --- a/templates/hooks--fsmonitor-watchman.sample +++ b/templates/hooks--fsmonitor-watchman.sample @@ -40,7 +40,8 @@ if ($system =~ m/^MSYS_NT/ || $system =~ m/^MINGW/) { $git_work_tree =~ s/[\r\n]+//g; $git_work_tree =~ s,\\,/,g; } else { - $git_work_tree = $ENV{'PWD'}; + $git_work_tree = `git rev-parse --show-toplevel`; + chomp $git_work_tree; } my $retry = 1; -- 2.15.0.rc1.417.g05670bb6e ^ permalink raw reply related [flat|nested] 21+ messages in thread
* [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver @ 2017-10-20 1:11 ` Alex Vandiver 2017-10-20 13:00 ` Johannes Schindelin 2017-10-20 1:11 ` [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR Alex Vandiver ` (2 subsequent siblings) 3 siblings, 1 reply; 21+ messages in thread From: Alex Vandiver @ 2017-10-20 1:11 UTC (permalink / raw) To: git; +Cc: Ben Peart, Alex Vandiver This provides small performance savings. Signed-off-by: Alex Vandiver <alexmv@dropbox.com> --- t/t7519/fsmonitor-watchman | 2 +- templates/hooks--fsmonitor-watchman.sample | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman index 377edc7be..eba46c78b 100755 --- a/t/t7519/fsmonitor-watchman +++ b/t/t7519/fsmonitor-watchman @@ -51,7 +51,7 @@ launch_watchman(); sub launch_watchman { - my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j') + my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j --no-pretty') or die "open2() failed: $!\n" . "Falling back to scanning...\n"; diff --git a/templates/hooks--fsmonitor-watchman.sample b/templates/hooks--fsmonitor-watchman.sample index 7df590d29..60eb7e70b 100755 --- a/templates/hooks--fsmonitor-watchman.sample +++ b/templates/hooks--fsmonitor-watchman.sample @@ -50,7 +50,7 @@ launch_watchman(); sub launch_watchman { - my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j') + my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j --no-pretty') or die "open2() failed: $!\n" . "Falling back to scanning...\n"; -- 2.15.0.rc1.417.g05670bb6e ^ permalink raw reply related [flat|nested] 21+ messages in thread
* Re: [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman 2017-10-20 1:11 ` [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman Alex Vandiver @ 2017-10-20 13:00 ` Johannes Schindelin 2017-10-20 13:17 ` Ben Peart 0 siblings, 1 reply; 21+ messages in thread From: Johannes Schindelin @ 2017-10-20 13:00 UTC (permalink / raw) To: Alex Vandiver; +Cc: git, Ben Peart Hi Alex, On Thu, 19 Oct 2017, Alex Vandiver wrote: > This provides small performance savings. > > diff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman > index 377edc7be..eba46c78b 100755 > --- a/t/t7519/fsmonitor-watchman > +++ b/t/t7519/fsmonitor-watchman > @@ -51,7 +51,7 @@ launch_watchman(); > > sub launch_watchman { > > - my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j') > + my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j --no-pretty') While I am very much infavor of this change (I was not aware of the --no-pretty option), I would like to see some statistics on that. Could you measure the impact, please, and include the results in the commit message? Ciao, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman 2017-10-20 13:00 ` Johannes Schindelin @ 2017-10-20 13:17 ` Ben Peart 2017-10-26 0:44 ` Alex Vandiver 0 siblings, 1 reply; 21+ messages in thread From: Ben Peart @ 2017-10-20 13:17 UTC (permalink / raw) To: Johannes Schindelin, Alex Vandiver; +Cc: git On 10/20/2017 9:00 AM, Johannes Schindelin wrote: > Hi Alex, > > On Thu, 19 Oct 2017, Alex Vandiver wrote: > >> This provides small performance savings. >> >> diff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman >> index 377edc7be..eba46c78b 100755 >> --- a/t/t7519/fsmonitor-watchman >> +++ b/t/t7519/fsmonitor-watchman >> @@ -51,7 +51,7 @@ launch_watchman(); >> >> sub launch_watchman { >> >> - my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j') >> + my $pid = open2(\*CHLD_OUT, \*CHLD_IN, 'watchman -j --no-pretty') > > While I am very much infavor of this change (I was not aware of the > --no-pretty option), I would like to see some statistics on that. Could > you measure the impact, please, and include the results in the commit > message? > > Ciao, > Johannes > I was also unaware of the --no-pretty option. I've tested this on Windows running version 4.9.0 of Watchman and verified that it does work correctly. I'm also curious if it produces any measurable difference in performance. ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman 2017-10-20 13:17 ` Ben Peart @ 2017-10-26 0:44 ` Alex Vandiver 2017-10-27 15:13 ` Johannes Schindelin 0 siblings, 1 reply; 21+ messages in thread From: Alex Vandiver @ 2017-10-26 0:44 UTC (permalink / raw) To: Ben Peart; +Cc: Johannes Schindelin, git On Fri, 20 Oct 2017, Ben Peart wrote: > > While I am very much infavor of this change (I was not aware of the > > --no-pretty option), I would like to see some statistics on that. Could > > you measure the impact, please, and include the results in the commit > > message? > > > > Ciao, > > Johannes > > > > I was also unaware of the --no-pretty option. I've tested this on Windows > running version 4.9.0 of Watchman and verified that it does work correctly. > I'm also curious if it produces any measurable difference in performance. On a repository with ~160k files, the following test harness, which requests all files inside the repository and parses that output: --------------8<----------- #!/usr/bin/perl use strict; use warnings; use IPC::Open2; my $pid = open2(\*CHLD_OUT, \*CHLD_IN, "watchman -j @ARGV") or die "open2() failed: $!\n" . "Falling back to scanning...\n"; my $query = qq|["query", "$ENV{PWD}", {}]|; print CHLD_IN $query; close CHLD_IN; my $response = do {local $/; <CHLD_OUT>}; my $json_pkg; eval { require JSON::XS; $json_pkg = "JSON::XS"; 1; } or do { require JSON::PP; $json_pkg = "JSON::PP"; }; my $o = $json_pkg->new->utf8->decode($response); --------------8<----------- ...run with dumbbench[1], produces: $ dumbbench -- ./test.pl cmd: Ran 22 iterations (2 outliers). cmd: Rounded run time per iteration: 5.240e+00 +/- 1.1e-02 (0.2%) $ dumbbench -- ./test.pl --no-pretty cmd: Ran 21 iterations (1 outliers). cmd: Rounded run time per iteration: 4.866e+00 +/- 1.3e-02 (0.3%) ...so a modest 8% speedup. I note that those numbers are for a perl with JSON::XS installed; without it installed, the runtime is so long that I gave up waiting for it. Anyways, I'll put that in the commit message in the re-roll. - Alex [1] https://metacpan.org/release/Dumbbench ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman 2017-10-26 0:44 ` Alex Vandiver @ 2017-10-27 15:13 ` Johannes Schindelin 0 siblings, 0 replies; 21+ messages in thread From: Johannes Schindelin @ 2017-10-27 15:13 UTC (permalink / raw) To: Alex Vandiver; +Cc: Ben Peart, git Hi Alex, On Wed, 25 Oct 2017, Alex Vandiver wrote: > [Johannes asked about the speedup when using --no-pretty] > > ...so a modest 8% speedup. I note that those numbers are for a perl > with JSON::XS installed; without it installed, the runtime is so long > that I gave up waiting for it. Very nice! AFAIR Git for Windows does *not* come with JSON::XS. > Anyways, I'll put that in the commit message in the re-roll. Thank you, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
* [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver 2017-10-20 1:11 ` [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman Alex Vandiver @ 2017-10-20 1:11 ` Alex Vandiver 2017-10-20 13:19 ` Ben Peart 2017-10-20 1:11 ` [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged Alex Vandiver 2017-10-20 12:58 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Johannes Schindelin 3 siblings, 1 reply; 21+ messages in thread From: Alex Vandiver @ 2017-10-20 1:11 UTC (permalink / raw) To: git; +Cc: Ben Peart, Alex Vandiver Signed-off-by: Alex Vandiver <alexmv@dropbox.com> --- Documentation/git.txt | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/Documentation/git.txt b/Documentation/git.txt index 1fca63634..720db196e 100644 --- a/Documentation/git.txt +++ b/Documentation/git.txt @@ -594,6 +594,10 @@ into it. Unsetting the variable, or setting it to empty, "0" or "false" (case insensitive) disables trace messages. +`GIT_TRACE_FSMONITOR`:: + Enables trace messages for the filesystem monitor extension. + See `GIT_TRACE` for available trace output options. + `GIT_TRACE_PACK_ACCESS`:: Enables trace messages for all accesses to any packs. For each access, the pack file name and an offset in the pack is -- 2.15.0.rc1.417.g05670bb6e ^ permalink raw reply related [flat|nested] 21+ messages in thread
* Re: [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR 2017-10-20 1:11 ` [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR Alex Vandiver @ 2017-10-20 13:19 ` Ben Peart 0 siblings, 0 replies; 21+ messages in thread From: Ben Peart @ 2017-10-20 13:19 UTC (permalink / raw) To: Alex Vandiver, git On 10/19/2017 9:11 PM, Alex Vandiver wrote: > Signed-off-by: Alex Vandiver <alexmv@dropbox.com> > --- > Documentation/git.txt | 4 ++++ > 1 file changed, 4 insertions(+) > > diff --git a/Documentation/git.txt b/Documentation/git.txt > index 1fca63634..720db196e 100644 > --- a/Documentation/git.txt > +++ b/Documentation/git.txt > @@ -594,6 +594,10 @@ into it. > Unsetting the variable, or setting it to empty, "0" or > "false" (case insensitive) disables trace messages. > > +`GIT_TRACE_FSMONITOR`:: > + Enables trace messages for the filesystem monitor extension. > + See `GIT_TRACE` for available trace output options. > + > `GIT_TRACE_PACK_ACCESS`:: > Enables trace messages for all accesses to any packs. For each > access, the pack file name and an offset in the pack is > Looks like a reasonable addition. Thank you. ^ permalink raw reply [flat|nested] 21+ messages in thread
* [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver 2017-10-20 1:11 ` [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman Alex Vandiver 2017-10-20 1:11 ` [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR Alex Vandiver @ 2017-10-20 1:11 ` Alex Vandiver 2017-10-20 13:16 ` Johannes Schindelin 2017-10-20 12:58 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Johannes Schindelin 3 siblings, 1 reply; 21+ messages in thread From: Alex Vandiver @ 2017-10-20 1:11 UTC (permalink / raw) To: git; +Cc: Ben Peart, Alex Vandiver If the fsmonitor extension is used in conjunction with the split index extension, the set of entries in the index when it is first loaded is only a subset of the real index. This leads to only the non-"base" index being marked as CE_FSMONITOR_VALID. Delay the expansion of the ewah bitmap until after tweak_split_index has been called to merge in the base index as well. Signed-off-by: Alex Vandiver <alexmv@dropbox.com> --- cache.h | 1 + fsmonitor.c | 38 ++++++++++++++++++++++++-------------- read-cache.c | 4 ++++ 3 files changed, 29 insertions(+), 14 deletions(-) diff --git a/cache.h b/cache.h index 25adcf681..0a4f43ec2 100644 --- a/cache.h +++ b/cache.h @@ -348,6 +348,7 @@ struct index_state { unsigned char sha1[20]; struct untracked_cache *untracked; uint64_t fsmonitor_last_update; + struct ewah_bitmap *fsmonitor_dirty; }; extern struct index_state the_index; diff --git a/fsmonitor.c b/fsmonitor.c index 7c1540c05..4c2668f57 100644 --- a/fsmonitor.c +++ b/fsmonitor.c @@ -49,20 +49,7 @@ int read_fsmonitor_extension(struct index_state *istate, const void *data, ewah_free(fsmonitor_dirty); return error("failed to parse ewah bitmap reading fsmonitor index extension"); } - - if (git_config_get_fsmonitor()) { - /* Mark all entries valid */ - for (i = 0; i < istate->cache_nr; i++) - istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; - - /* Mark all previously saved entries as dirty */ - ewah_each_bit(fsmonitor_dirty, fsmonitor_ewah_callback, istate); - - /* Now mark the untracked cache for fsmonitor usage */ - if (istate->untracked) - istate->untracked->use_fsmonitor = 1; - } - ewah_free(fsmonitor_dirty); + istate->fsmonitor_dirty = fsmonitor_dirty; trace_printf_key(&trace_fsmonitor, "read fsmonitor extension successful"); return 0; @@ -238,6 +225,29 @@ void remove_fsmonitor(struct index_state *istate) void tweak_fsmonitor(struct index_state *istate) { + int i; + + if (istate->fsmonitor_dirty) { + /* Mark all entries valid */ + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); + for (i = 0; i < istate->cache_nr; i++) { + istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; + } + trace_printf_key(&trace_fsmonitor, "marked all as valid"); + + /* Mark all previously saved entries as dirty */ + trace_printf_key(&trace_fsmonitor, "setting each bit on %p", istate->fsmonitor_dirty); + ewah_each_bit(istate->fsmonitor_dirty, fsmonitor_ewah_callback, istate); + + /* Now mark the untracked cache for fsmonitor usage */ + trace_printf_key(&trace_fsmonitor, "setting untracked state"); + if (istate->untracked) + istate->untracked->use_fsmonitor = 1; + ewah_free(istate->fsmonitor_dirty); + } else { + trace_printf_key(&trace_fsmonitor, "fsmonitor not enabled"); + } + switch (git_config_get_fsmonitor()) { case -1: /* keep: do nothing */ break; diff --git a/read-cache.c b/read-cache.c index c18e5e623..3b5cd00a2 100644 --- a/read-cache.c +++ b/read-cache.c @@ -330,6 +330,10 @@ int ie_match_stat(struct index_state *istate, return 0; if (!ignore_fsmonitor && (ce->ce_flags & CE_FSMONITOR_VALID)) return 0; + if (ce->ce_flags & CE_FSMONITOR_VALID) + trace_printf_key(&trace_fsmonitor, "fsmon marked valid for %s", ce->name); + if (ignore_fsmonitor) + trace_printf_key(&trace_fsmonitor, "Ignoring fsmonitor for %s", ce->name); /* * Intent-to-add entries have not been added, so the index entry -- 2.15.0.rc1.417.g05670bb6e ^ permalink raw reply related [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 1:11 ` [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged Alex Vandiver @ 2017-10-20 13:16 ` Johannes Schindelin 2017-10-20 21:47 ` Ben Peart ` (2 more replies) 0 siblings, 3 replies; 21+ messages in thread From: Johannes Schindelin @ 2017-10-20 13:16 UTC (permalink / raw) To: Alex Vandiver; +Cc: git, Ben Peart Hi Alex, On Thu, 19 Oct 2017, Alex Vandiver wrote: > extern struct index_state the_index; > diff --git a/fsmonitor.c b/fsmonitor.c > index 7c1540c05..4c2668f57 100644 > --- a/fsmonitor.c > +++ b/fsmonitor.c > @@ -49,20 +49,7 @@ int read_fsmonitor_extension(struct index_state *istate, const void *data, > ewah_free(fsmonitor_dirty); > return error("failed to parse ewah bitmap reading fsmonitor index extension"); > } > - > - if (git_config_get_fsmonitor()) { > - /* Mark all entries valid */ > - for (i = 0; i < istate->cache_nr; i++) > - istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; > - > - /* Mark all previously saved entries as dirty */ > - ewah_each_bit(fsmonitor_dirty, fsmonitor_ewah_callback, istate); > - > - /* Now mark the untracked cache for fsmonitor usage */ > - if (istate->untracked) > - istate->untracked->use_fsmonitor = 1; > - } > - ewah_free(fsmonitor_dirty); > + istate->fsmonitor_dirty = fsmonitor_dirty; From the diff, it is not immediately clear that fsmonitor_dirty is not leaked in any code path. Could you clarify this in the commit message, please? > @@ -238,6 +225,29 @@ void remove_fsmonitor(struct index_state *istate) > > void tweak_fsmonitor(struct index_state *istate) > { > + int i; > + > + if (istate->fsmonitor_dirty) { > + /* Mark all entries valid */ > + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); Sadly, a call to trace_printf_key() is not really a noop when tracing is disabled. The call to trace_printf_key() hands off to trace_vprintf_fl(), which in turn calls prepare_trace_line() which asks trace_want() whether we need to trace, which finally calls get_trace_fd(). This last function initializes a trace key if needed, and this entire call stack takes time. In this case, where we trace whether fsmonitor is enabled essentially once during the life cycle of the current Git command invocation, it may be okay, but later we perform a trace for every single ie_match_stat() call, which I think should be guarded to avoid unnecessary code churn in performance critical code paths (O(N) is pretty good until the constant factor becomes large). > + for (i = 0; i < istate->cache_nr; i++) { > + istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; > + } > + trace_printf_key(&trace_fsmonitor, "marked all as valid"); > + > + /* Mark all previously saved entries as dirty */ > + trace_printf_key(&trace_fsmonitor, "setting each bit on %p", istate->fsmonitor_dirty); > + ewah_each_bit(istate->fsmonitor_dirty, fsmonitor_ewah_callback, istate); > + > + /* Now mark the untracked cache for fsmonitor usage */ > + trace_printf_key(&trace_fsmonitor, "setting untracked state"); > + if (istate->untracked) > + istate->untracked->use_fsmonitor = 1; > + ewah_free(istate->fsmonitor_dirty); At this point, please set istate->fsmonitor_dirty = NULL, as it is not immediately obvious from this patch (or from the postimage of this diff) that the array is not used later on. > + } else { > + trace_printf_key(&trace_fsmonitor, "fsmonitor not enabled"); > + } > + > switch (git_config_get_fsmonitor()) { > case -1: /* keep: do nothing */ > break; > diff --git a/read-cache.c b/read-cache.c > index c18e5e623..3b5cd00a2 100644 > --- a/read-cache.c > +++ b/read-cache.c > @@ -330,6 +330,10 @@ int ie_match_stat(struct index_state *istate, > return 0; > if (!ignore_fsmonitor && (ce->ce_flags & CE_FSMONITOR_VALID)) > return 0; > + if (ce->ce_flags & CE_FSMONITOR_VALID) > + trace_printf_key(&trace_fsmonitor, "fsmon marked valid for %s", ce->name); > + if (ignore_fsmonitor) > + trace_printf_key(&trace_fsmonitor, "Ignoring fsmonitor for %s", ce->name); This is the code path I am fairly certain should not be penalized if tracing is disabled. Ciao, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 13:16 ` Johannes Schindelin @ 2017-10-20 21:47 ` Ben Peart 2017-10-21 2:06 ` Junio C Hamano 2017-10-21 3:35 ` Jeff King 2017-10-26 1:20 ` Alex Vandiver 2 siblings, 1 reply; 21+ messages in thread From: Ben Peart @ 2017-10-20 21:47 UTC (permalink / raw) To: Johannes Schindelin, Alex Vandiver; +Cc: git On 10/20/2017 9:16 AM, Johannes Schindelin wrote: > Hi Alex, > > On Thu, 19 Oct 2017, Alex Vandiver wrote: > >> extern struct index_state the_index; >> diff --git a/fsmonitor.c b/fsmonitor.c >> index 7c1540c05..4c2668f57 100644 >> --- a/fsmonitor.c >> +++ b/fsmonitor.c >> @@ -49,20 +49,7 @@ int read_fsmonitor_extension(struct index_state *istate, const void *data, >> ewah_free(fsmonitor_dirty); >> return error("failed to parse ewah bitmap reading fsmonitor index extension"); >> } >> - >> - if (git_config_get_fsmonitor()) { >> - /* Mark all entries valid */ >> - for (i = 0; i < istate->cache_nr; i++) >> - istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; >> - >> - /* Mark all previously saved entries as dirty */ >> - ewah_each_bit(fsmonitor_dirty, fsmonitor_ewah_callback, istate); >> - >> - /* Now mark the untracked cache for fsmonitor usage */ >> - if (istate->untracked) >> - istate->untracked->use_fsmonitor = 1; >> - } >> - ewah_free(fsmonitor_dirty); >> + istate->fsmonitor_dirty = fsmonitor_dirty; > > From the diff, it is not immediately clear that fsmonitor_dirty is not > leaked in any code path. > > Could you clarify this in the commit message, please? > >> @@ -238,6 +225,29 @@ void remove_fsmonitor(struct index_state *istate) >> >> void tweak_fsmonitor(struct index_state *istate) >> { >> + int i; >> + Here we should test git_config_get_fsmonitor() (see the logic where you moved this from) as there is no reason to set up the fsmonitor state if we're about to remove the extension. Save the results and use them in the case statement below. >> + if (istate->fsmonitor_dirty) { >> + /* Mark all entries valid */ >> + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); > > Sadly, a call to trace_printf_key() is not really a noop when tracing is > disabled. The call to trace_printf_key() hands off to trace_vprintf_fl(), > which in turn calls prepare_trace_line() which asks trace_want() whether > we need to trace, which finally calls get_trace_fd(). This last function > initializes a trace key if needed, and this entire call stack takes time. > > In this case, where we trace whether fsmonitor is enabled essentially once > during the life cycle of the current Git command invocation, it may be > okay, but later we perform a trace for every single ie_match_stat() call, > which I think should be guarded to avoid unnecessary code churn in > performance critical code paths (O(N) is pretty good until the constant > factor becomes large). > >> + for (i = 0; i < istate->cache_nr; i++) { >> + istate->cache[i]->ce_flags |= CE_FSMONITOR_VALID; >> + } >> + trace_printf_key(&trace_fsmonitor, "marked all as valid"); >> + >> + /* Mark all previously saved entries as dirty */ >> + trace_printf_key(&trace_fsmonitor, "setting each bit on %p", istate->fsmonitor_dirty); >> + ewah_each_bit(istate->fsmonitor_dirty, fsmonitor_ewah_callback, istate); >> + >> + /* Now mark the untracked cache for fsmonitor usage */ >> + trace_printf_key(&trace_fsmonitor, "setting untracked state"); >> + if (istate->untracked) >> + istate->untracked->use_fsmonitor = 1; >> + ewah_free(istate->fsmonitor_dirty); > > At this point, please set istate->fsmonitor_dirty = NULL, as it is not > immediately obvious from this patch (or from the postimage of this diff) > that the array is not used later on. > >> + } else { >> + trace_printf_key(&trace_fsmonitor, "fsmonitor not enabled"); >> + } >> + I'd remove the trace statement above as it isn't always accurate. fsmonitor could be enabled but just hasn't written/read the extension yet. >> switch (git_config_get_fsmonitor()) { >> case -1: /* keep: do nothing */ >> break; >> diff --git a/read-cache.c b/read-cache.c >> index c18e5e623..3b5cd00a2 100644 >> --- a/read-cache.c >> +++ b/read-cache.c >> @@ -330,6 +330,10 @@ int ie_match_stat(struct index_state *istate, >> return 0; >> if (!ignore_fsmonitor && (ce->ce_flags & CE_FSMONITOR_VALID)) >> return 0; >> + if (ce->ce_flags & CE_FSMONITOR_VALID) >> + trace_printf_key(&trace_fsmonitor, "fsmon marked valid for %s", ce->name); >> + if (ignore_fsmonitor) >> + trace_printf_key(&trace_fsmonitor, "Ignoring fsmonitor for %s", ce->name); > > This is the code path I am fairly certain should not be penalized if > tracing is disabled. > Definitely agree with the need to remove this tracing as it will get called a lot and we don't want to pay the perf penalty. > Ciao, > Johannes > Thank you for detecting the issue with split index and even better, sending patches to fix it! ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 21:47 ` Ben Peart @ 2017-10-21 2:06 ` Junio C Hamano 0 siblings, 0 replies; 21+ messages in thread From: Junio C Hamano @ 2017-10-21 2:06 UTC (permalink / raw) To: Ben Peart; +Cc: Johannes Schindelin, Alex Vandiver, git Ben Peart <peartben@gmail.com> writes: >>> + } else { >>> + trace_printf_key(&trace_fsmonitor, "fsmonitor not enabled"); >>> + } >>> + > > I'd remove the trace statement above as it isn't always > accurate. fsmonitor could be enabled but just hasn't written/read the > extension yet. I agree; when it is not enabled, we shouldn't be paying the penalty, either. I wonder if tweak_*() function can return early upfront if we know fsmonitor is not enabled to make it even more obvious. >>> + if (ignore_fsmonitor) >>> + trace_printf_key(&trace_fsmonitor, "Ignoring fsmonitor for %s", ce->name); >> >> This is the code path I am fairly certain should not be penalized if >> tracing is disabled. > > Definitely agree with the need to remove this tracing as it will get > called a lot and we don't want to pay the perf penalty. Yes. ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 13:16 ` Johannes Schindelin 2017-10-20 21:47 ` Ben Peart @ 2017-10-21 3:35 ` Jeff King 2017-10-23 9:57 ` Johannes Schindelin 2017-10-26 1:20 ` Alex Vandiver 2 siblings, 1 reply; 21+ messages in thread From: Jeff King @ 2017-10-21 3:35 UTC (permalink / raw) To: Johannes Schindelin; +Cc: Alex Vandiver, git, Ben Peart On Fri, Oct 20, 2017 at 03:16:20PM +0200, Johannes Schindelin wrote: > > void tweak_fsmonitor(struct index_state *istate) > > { > > + int i; > > + > > + if (istate->fsmonitor_dirty) { > > + /* Mark all entries valid */ > > + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); > > Sadly, a call to trace_printf_key() is not really a noop when tracing is > disabled. The call to trace_printf_key() hands off to trace_vprintf_fl(), > which in turn calls prepare_trace_line() which asks trace_want() whether > we need to trace, which finally calls get_trace_fd(). This last function > initializes a trace key if needed, and this entire call stack takes time. It seems like we could pretty easily turn noop traces into a trivial conditional, like: diff --git a/trace.h b/trace.h index 179b249c59..c46b92cbde 100644 --- a/trace.h +++ b/trace.h @@ -80,8 +80,11 @@ extern void trace_performance_since(uint64_t start, const char *format, ...); #define trace_printf(...) \ trace_printf_key_fl(TRACE_CONTEXT, __LINE__, NULL, __VA_ARGS__) -#define trace_printf_key(key, ...) \ - trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) +#define trace_printf_key(key, ...) do { \ + if (!key->initialized || key->fd) \ + trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) \ +} while(0) + #define trace_argv_printf(argv, ...) \ trace_argv_printf_fl(TRACE_CONTEXT, __LINE__, argv, __VA_ARGS__) (OK, that's got an OR, but if we are really pinching instructions we could obviously store a single "I've been initialized and am disabled" flag). I don't have an opinion one way or the other on these particular messages, but in general I'd like to see _more_ tracing in Git, not less. I've often traced Git with a debugger or other tools like perf, but there's real value in the author of code annotating high-level logical events. -Peff ^ permalink raw reply related [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-21 3:35 ` Jeff King @ 2017-10-23 9:57 ` Johannes Schindelin 2017-10-23 12:36 ` Ben Peart 0 siblings, 1 reply; 21+ messages in thread From: Johannes Schindelin @ 2017-10-23 9:57 UTC (permalink / raw) To: Jeff King; +Cc: Alex Vandiver, git, Ben Peart Hi Peff, On Fri, 20 Oct 2017, Jeff King wrote: > On Fri, Oct 20, 2017 at 03:16:20PM +0200, Johannes Schindelin wrote: > > > > void tweak_fsmonitor(struct index_state *istate) > > > { > > > + int i; > > > + > > > + if (istate->fsmonitor_dirty) { > > > + /* Mark all entries valid */ > > > + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); > > > > Sadly, a call to trace_printf_key() is not really a noop when tracing is > > disabled. The call to trace_printf_key() hands off to trace_vprintf_fl(), > > which in turn calls prepare_trace_line() which asks trace_want() whether > > we need to trace, which finally calls get_trace_fd(). This last function > > initializes a trace key if needed, and this entire call stack takes time. > > It seems like we could pretty easily turn noop traces into a trivial > conditional, like: > > diff --git a/trace.h b/trace.h > index 179b249c59..c46b92cbde 100644 > --- a/trace.h > +++ b/trace.h > @@ -80,8 +80,11 @@ extern void trace_performance_since(uint64_t start, const char *format, ...); > #define trace_printf(...) \ > trace_printf_key_fl(TRACE_CONTEXT, __LINE__, NULL, __VA_ARGS__) > > -#define trace_printf_key(key, ...) \ > - trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) > +#define trace_printf_key(key, ...) do { \ > + if (!key->initialized || key->fd) \ > + trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) \ > +} while(0) > + > > #define trace_argv_printf(argv, ...) \ > trace_argv_printf_fl(TRACE_CONTEXT, __LINE__, argv, __VA_ARGS__) > > > (OK, that's got an OR, but if we are really pinching instructions we > could obviously store a single "I've been initialized and am disabled" > flag). I'd really like that. > I don't have an opinion one way or the other on these particular > messages, but in general I'd like to see _more_ tracing in Git, not > less. I've often traced Git with a debugger or other tools like perf, > but there's real value in the author of code annotating high-level > logical events. Yes, I like that idea, too: to add more tracing. Thanks, Dscho ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-23 9:57 ` Johannes Schindelin @ 2017-10-23 12:36 ` Ben Peart 0 siblings, 0 replies; 21+ messages in thread From: Ben Peart @ 2017-10-23 12:36 UTC (permalink / raw) To: Johannes Schindelin, Jeff King; +Cc: Alex Vandiver, git On 10/23/2017 5:57 AM, Johannes Schindelin wrote: > Hi Peff, > > On Fri, 20 Oct 2017, Jeff King wrote: > >> On Fri, Oct 20, 2017 at 03:16:20PM +0200, Johannes Schindelin wrote: >> >>>> void tweak_fsmonitor(struct index_state *istate) >>>> { >>>> + int i; >>>> + >>>> + if (istate->fsmonitor_dirty) { >>>> + /* Mark all entries valid */ >>>> + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); >>> >>> Sadly, a call to trace_printf_key() is not really a noop when tracing is >>> disabled. The call to trace_printf_key() hands off to trace_vprintf_fl(), >>> which in turn calls prepare_trace_line() which asks trace_want() whether >>> we need to trace, which finally calls get_trace_fd(). This last function >>> initializes a trace key if needed, and this entire call stack takes time. >> >> It seems like we could pretty easily turn noop traces into a trivial >> conditional, like: >> >> diff --git a/trace.h b/trace.h >> index 179b249c59..c46b92cbde 100644 >> --- a/trace.h >> +++ b/trace.h >> @@ -80,8 +80,11 @@ extern void trace_performance_since(uint64_t start, const char *format, ...); >> #define trace_printf(...) \ >> trace_printf_key_fl(TRACE_CONTEXT, __LINE__, NULL, __VA_ARGS__) >> >> -#define trace_printf_key(key, ...) \ >> - trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) >> +#define trace_printf_key(key, ...) do { \ >> + if (!key->initialized || key->fd) \ >> + trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__) \ >> +} while(0) >> + >> >> #define trace_argv_printf(argv, ...) \ >> trace_argv_printf_fl(TRACE_CONTEXT, __LINE__, argv, __VA_ARGS__) >> >> >> (OK, that's got an OR, but if we are really pinching instructions we >> could obviously store a single "I've been initialized and am disabled" >> flag). > > I'd really like that. > >> I don't have an opinion one way or the other on these particular >> messages, but in general I'd like to see _more_ tracing in Git, not >> less. I've often traced Git with a debugger or other tools like perf, >> but there's real value in the author of code annotating high-level >> logical events. > > Yes, I like that idea, too: to add more tracing. > > Thanks, > Dscho > Two big thumbs up. I find turning on tracking very informative as I can better see the flow of execution and sometimes am surprised by what I discover. :) I've often added additional tracing while working on a feature only to remove it before submitting the patch because of the performance overhead. Being able to leave that in would be very helpful. ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged 2017-10-20 13:16 ` Johannes Schindelin 2017-10-20 21:47 ` Ben Peart 2017-10-21 3:35 ` Jeff King @ 2017-10-26 1:20 ` Alex Vandiver 2 siblings, 0 replies; 21+ messages in thread From: Alex Vandiver @ 2017-10-26 1:20 UTC (permalink / raw) To: Johannes Schindelin; +Cc: git, Ben Peart On Fri, 20 Oct 2017, Johannes Schindelin wrote: > From the diff, it is not immediately clear that fsmonitor_dirty is not > leaked in any code path. > > Could you clarify this in the commit message, please? Will do! > > @@ -238,6 +225,29 @@ void remove_fsmonitor(struct index_state *istate) > > > > void tweak_fsmonitor(struct index_state *istate) > > { > > + int i; > > + > > + if (istate->fsmonitor_dirty) { > > + /* Mark all entries valid */ > > + trace_printf_key(&trace_fsmonitor, "fsmonitor is enabled; cache is %d", istate->cache_nr); > > Sadly, a call to trace_printf_key() is not really a noop when tracing is > disabled. [snip] Apologies -- I'd meant to remove the tracing before committing. I think we're all on the same page that it would be nice to lower the impact of tracing to let it be more prevalent, but I'd rather not block these changes on that. Thanks for the comments! - Alex ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver ` (2 preceding siblings ...) 2017-10-20 1:11 ` [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged Alex Vandiver @ 2017-10-20 12:58 ` Johannes Schindelin 2017-10-26 0:20 ` Alex Vandiver 3 siblings, 1 reply; 21+ messages in thread From: Johannes Schindelin @ 2017-10-20 12:58 UTC (permalink / raw) To: Alex Vandiver; +Cc: git, Ben Peart Hi Alex, On Thu, 19 Oct 2017, Alex Vandiver wrote: > Signed-off-by: Alex Vandiver <alexmv@dropbox.com> > --- > t/t7519/fsmonitor-watchman | 3 ++- > templates/hooks--fsmonitor-watchman.sample | 3 ++- > 2 files changed, 4 insertions(+), 2 deletions(-) > > diff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman > index a3e30bf54..377edc7be 100755 > --- a/t/t7519/fsmonitor-watchman > +++ b/t/t7519/fsmonitor-watchman > @@ -41,7 +41,8 @@ if ($system =~ m/^MSYS_NT/ || $system =~ m/^MINGW/) { > $git_work_tree =~ s/[\r\n]+//g; > $git_work_tree =~ s,\\,/,g; > } else { > - $git_work_tree = $ENV{'PWD'}; > + $git_work_tree = `git rev-parse --show-toplevel`; > + chomp $git_work_tree; This is super expensive, as it means a full-blown new process instead of just a simple environment variable expansion. The idea behind using `PWD` instead was that Git will already have done all of the work of figuring out the top-level directory and switched to there before calling the fsmonitor hook. Did you see any case where the script was *not* called from the top-level directory? Ciao, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD 2017-10-20 12:58 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Johannes Schindelin @ 2017-10-26 0:20 ` Alex Vandiver 2017-10-27 15:11 ` Johannes Schindelin 0 siblings, 1 reply; 21+ messages in thread From: Alex Vandiver @ 2017-10-26 0:20 UTC (permalink / raw) To: Johannes Schindelin; +Cc: git, Ben Peart On Fri, 20 Oct 2017, Johannes Schindelin wrote: > This is super expensive, as it means a full-blown new process instead of > just a simple environment variable expansion. > > The idea behind using `PWD` instead was that Git will already have done > all of the work of figuring out the top-level directory and switched to > there before calling the fsmonitor hook. I'm not seeing that PWD has been at all altered. The following does seem like a better solution: ------8<----- diff --git a/fsmonitor.c b/fsmonitor.c index 7c1540c05..4ea44dcc6 100644 --- a/fsmonitor.c +++ b/fsmonitor.c @@ -121,6 +121,7 @@ static int query_fsmonitor(int version, uint64_t last_update, struct strbuf *que argv[3] = NULL; cp.argv = argv; cp.use_shell = 1; + cp.dir = get_git_work_tree(); return capture_command(&cp, query_result, 1024); } ------8<----- I'll re-roll with that. > Did you see any case where the script was *not* called from the top-level > directory? Merely calling `git status` inside a subdirectory is enough to for the stock watchman config to report that it's in a "new" directory: $ watchman watch-list { "roots": [], "version": "4.7.0" } $ git status Adding '/Users/alexmv/src/git' to watchman's watch list. On branch test nothing to commit, working tree clean $ cd builtin/ $ git status Adding '/Users/alexmv/src/git/builtin' to watchman's watch list. On branch test nothing to commit, working tree clean $ watchman watch-list { "roots": [ "/Users/alexmv/src/git/builtin", "/Users/alexmv/src/git" ], "version": "4.7.0" } As I understand it, that means that it then loses all performance gains in the new directory, as it spits out "all dirty." - Alex ^ permalink raw reply related [flat|nested] 21+ messages in thread
* Re: [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD 2017-10-26 0:20 ` Alex Vandiver @ 2017-10-27 15:11 ` Johannes Schindelin 0 siblings, 0 replies; 21+ messages in thread From: Johannes Schindelin @ 2017-10-27 15:11 UTC (permalink / raw) To: Alex Vandiver; +Cc: git, Ben Peart Hi Alex, On Wed, 25 Oct 2017, Alex Vandiver wrote: > On Fri, 20 Oct 2017, Johannes Schindelin wrote: > > This is super expensive, as it means a full-blown new process instead of > > just a simple environment variable expansion. > > > > The idea behind using `PWD` instead was that Git will already have done > > all of the work of figuring out the top-level directory and switched to > > there before calling the fsmonitor hook. > > I'm not seeing that PWD has been at all altered. No, PWD is not altered. But a simple environment variable expansion (fast) was replaced by spawning to `git rev-parse --show-top-level` (slow, ~60ms on Windows). *That* is expensive. Ciao, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
* Re: [PATCH 0/4] fsmonitor fixes 2017-10-20 1:11 [PATCH 0/4] fsmonitor fixes Alex Vandiver 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver @ 2017-10-20 13:17 ` Johannes Schindelin 1 sibling, 0 replies; 21+ messages in thread From: Johannes Schindelin @ 2017-10-20 13:17 UTC (permalink / raw) To: Alex Vandiver; +Cc: git, Ben Peart Hi Alex, On Thu, 19 Oct 2017, Alex Vandiver wrote: > A few fixes found from playing around with the fsmonitor branch in > next. Thank you for having a look, and even better: for sending a couple of improvements on top of Ben's & my work. I sent a couple of suggestions and hope you will find the useful? Ciao, Johannes ^ permalink raw reply [flat|nested] 21+ messages in thread
end of thread, other threads:[~2017-10-27 15:13 UTC | newest] Thread overview: 21+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2017-10-20 1:11 [PATCH 0/4] fsmonitor fixes Alex Vandiver 2017-10-20 1:11 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Alex Vandiver 2017-10-20 1:11 ` [PATCH 2/4] fsmonitor: Don't bother pretty-printing JSON from watchman Alex Vandiver 2017-10-20 13:00 ` Johannes Schindelin 2017-10-20 13:17 ` Ben Peart 2017-10-26 0:44 ` Alex Vandiver 2017-10-27 15:13 ` Johannes Schindelin 2017-10-20 1:11 ` [PATCH 3/4] fsmonitor: Document GIT_TRACE_FSMONITOR Alex Vandiver 2017-10-20 13:19 ` Ben Peart 2017-10-20 1:11 ` [PATCH 4/4] fsmonitor: Delay updating state until after split index is merged Alex Vandiver 2017-10-20 13:16 ` Johannes Schindelin 2017-10-20 21:47 ` Ben Peart 2017-10-21 2:06 ` Junio C Hamano 2017-10-21 3:35 ` Jeff King 2017-10-23 9:57 ` Johannes Schindelin 2017-10-23 12:36 ` Ben Peart 2017-10-26 1:20 ` Alex Vandiver 2017-10-20 12:58 ` [PATCH 1/4] fsmonitor: Watch, and ask about, the top of the repo, not the CWD Johannes Schindelin 2017-10-26 0:20 ` Alex Vandiver 2017-10-27 15:11 ` Johannes Schindelin 2017-10-20 13:17 ` [PATCH 0/4] fsmonitor fixes Johannes Schindelin
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.