Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sparse Index: log why the index is being expanded #691

Merged
merged 6 commits into from
Oct 9, 2024

Conversation

derrickstolee
Copy link
Collaborator

@derrickstolee derrickstolee commented Sep 30, 2024

I will intend to send this upstream after the 2.47.0 release cycle, but this should get to our microsoft/git users for maximum impact.

Customers have been struggling with explaining why the sparse index expansion advice message is showing up. The advice to run 'git clean' has not always helped folks, and sometimes it is very unclear why we are running into trouble.

These changes introduce a way to log a reason for the expansion into the trace2 logs so it can be found by requesting that a user enable tracing.

While testing this, I created the most standard case that happens, which is to have an existing directory match a sparse directory in the index. In this case, it showed that two log messages were required. See the last commit for this new log message. Together, these two places show this kind of message in the GIT_TRACE2_PERF output (trimmed for clarity):

region_enter | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | ..skip-worktree sparsedir:<my-sparse-path>/
data         | index        | ..sparse_path_count:362
data         | index        | ..sparse_lstat_count:732
region_leave | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | expansion-reason:failed to clear skip-worktree while sparse

I added some tests to demonstrate that these logs are recorded, but it also seems difficult to hit some of these cases.

@derrickstolee derrickstolee self-assigned this Sep 30, 2024
It is sometimes difficult to support users who are hitting issues with
sparse index expansion because it is unclear why the index needs to expand
from logs alone. It is too invasive to set up a debugging scenario on the
user's machine, so let's improve the logging.

Create a new ensure_full_index_with_reason() method that takes a formatting
string and parameters. If the index is not fully expanded, then apply the
formatting logic to create the logged string and log it before calling
ensure_full_index(). This should assist with discovering why an index is
expanded from trace2 logs alone.

Signed-off-by: Derrick Stolee <[email protected]>
These locations that previously called ensure_full_index() are now
updated to call the ..._with_reason() varation using fixed strings that
should be enough to identify the reason for the expansion.

This will help users use tracing to determine why the index is expanding
in their scenarios.

Signed-off-by: Derrick Stolee <[email protected]>
These cases that call ensure_full_index() are likely to be due to a data
shape issue on a user's machine, so take the extra time to format a
message that can be placed in their trace2 output and hopefully identify
the problem that is leading to this slow behavior.

Signed-off-by: Derrick Stolee <[email protected]>
For safety, areas of code that iterate over the cache entries in the
index were guarded with ensure_full_index() and labeled with a comment.
Replace these with a macro that calls ensure_full_index_with_reason()
using the line number of the caller to help identify the situation that
is causing the index expansion.

Signed-off-by: Derrick Stolee <[email protected]>
The recent changes update the callers of ensure_full_index() to call
variants that will log extra information. This should assist developers
assisting users who are hitting the sparse index expansion message.

Signed-off-by: Derrick Stolee <[email protected]>
The clear_skip_worktree_from_present_files_sparse() method attempts to
clear the skip worktree bit from cache entries in the index depending on
when they exist in the workdir. When this comes across a sparse
directory that actually exists in the workdir, then this method fails
and signals that the index needs expansion.

The index expansion already logs a reason, but this reason is separate
from the path that caused this failure.

Add logging to demonstrate this situation for full clarity.

Signed-off-by: Derrick Stolee <[email protected]>
Copy link
Member

@dscho dscho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Very nice!

@dscho dscho merged commit 6c41ee7 into microsoft:vfs-2.46.2 Oct 9, 2024
48 checks passed
dscho added a commit that referenced this pull request Oct 9, 2024
I will intend to send this upstream after the 2.47.0 release cycle, but
this should get to our microsoft/git users for maximum impact.

Customers have been struggling with explaining why the sparse index
expansion advice message is showing up. The advice to run 'git clean'
has not always helped folks, and sometimes it is very unclear why we are
running into trouble.

These changes introduce a way to log a reason for the expansion into the
trace2 logs so it can be found by requesting that a user enable tracing.

While testing this, I created the most standard case that happens, which
is to have an existing directory match a sparse directory in the index.
In this case, it showed that two log messages were required. See the
last commit for this new log message. Together, these two places show
this kind of message in the `GIT_TRACE2_PERF` output (trimmed for
clarity):

```
region_enter | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | ..skip-worktree sparsedir:<my-sparse-path>/
data         | index        | ..sparse_path_count:362
data         | index        | ..sparse_lstat_count:732
region_leave | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | expansion-reason:failed to clear skip-worktree while sparse
```

I added some tests to demonstrate that these logs are recorded, but it
also seems difficult to hit some of these cases.
mjcheetham pushed a commit that referenced this pull request Dec 3, 2024
I will intend to send this upstream after the 2.47.0 release cycle, but
this should get to our microsoft/git users for maximum impact.

Customers have been struggling with explaining why the sparse index
expansion advice message is showing up. The advice to run 'git clean'
has not always helped folks, and sometimes it is very unclear why we are
running into trouble.

These changes introduce a way to log a reason for the expansion into the
trace2 logs so it can be found by requesting that a user enable tracing.

While testing this, I created the most standard case that happens, which
is to have an existing directory match a sparse directory in the index.
In this case, it showed that two log messages were required. See the
last commit for this new log message. Together, these two places show
this kind of message in the `GIT_TRACE2_PERF` output (trimmed for
clarity):

```
region_enter | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | ..skip-worktree sparsedir:<my-sparse-path>/
data         | index        | ..sparse_path_count:362
data         | index        | ..sparse_lstat_count:732
region_leave | index        | label:clear_skip_worktree_from_present_files_sparse
data         | sparse-index | expansion-reason:failed to clear skip-worktree while sparse
```

I added some tests to demonstrate that these logs are recorded, but it
also seems difficult to hit some of these cases.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants