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

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.

Documentation/technical/sparse-index.txt

@@ -206,3 +206,10 @@ Here are some commands that might be useful to update:
 * `git am`
 * `git clean`
 * `git stash`
+
+In order to help identify the cases where remaining index expansion is
+occurring in user machines, calls to `ensure_full_index()` have been
+replaced with `ensure_full_index_with_reason()` or with
+`ensure_full_index_unaudited()`. These versions add tracing that should
+help identify the reason for the index expansion without needing full
+access to someone's repository.

builtin/checkout-index.c

@@ -154,7 +154,8 @@ static int checkout_all(const char *prefix, int prefix_length)
 			 * first entry inside the expanded sparse directory).
 			 */
 			if (ignore_skip_worktree) {
-				ensure_full_index(the_repository->index);
+				ensure_full_index_with_reason(the_repository->index,
+							      "checkout-index");
 				ce = the_repository->index->cache[i];
 			}
 		}

builtin/commit.c

@@ -381,7 +381,7 @@ static int list_paths(struct string_list *list, const char *with_tree,
 	}
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(the_repository->index);
+	ensure_full_index_unaudited(the_repository->index);
 	for (i = 0; i < the_repository->index->cache_nr; i++) {
 		const struct cache_entry *ce = the_repository->index->cache[i];
 		struct string_list_item *item;
@@ -1119,7 +1119,7 @@ static int prepare_to_commit(const char *index_file, const char *prefix,
 			int i, ita_nr = 0;
 
 			/* TODO: audit for interaction with sparse-index. */
-			ensure_full_index(the_repository->index);
+			ensure_full_index_unaudited(the_repository->index);
 			for (i = 0; i < the_repository->index->cache_nr; i++)
 				if (ce_intent_to_add(the_repository->index->cache[i]))
 					ita_nr++;

builtin/difftool.c

@@ -586,7 +586,7 @@ static int run_dir_diff(const char *extcmd, int symlinks, const char *prefix,
 	ret = run_command(&cmd);
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(&wtindex);
+	ensure_full_index_unaudited(&wtindex);
 
 	/*
 	 * If the diff includes working copy files and those

builtin/fsck.c

@@ -815,7 +815,7 @@ static void fsck_index(struct index_state *istate, const char *index_path,
 	unsigned int i;
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(istate);
+	ensure_full_index_unaudited(istate);
 	for (i = 0; i < istate->cache_nr; i++) {
 		unsigned int mode;
 		struct blob *blob;

builtin/ls-files.c

@@ -410,7 +410,7 @@ static void show_files(struct repository *repo, struct dir_struct *dir)
 		return;
 
 	if (!show_sparse_dirs)
-		ensure_full_index(repo->index);
+		ensure_full_index_with_reason(repo->index, "ls-files");
 
 	for (i = 0; i < repo->index->cache_nr; i++) {
 		const struct cache_entry *ce = repo->index->cache[i];

builtin/merge-index.c

@@ -64,7 +64,7 @@ static void merge_all(void)
 {
 	int i;
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(the_repository->index);
+	ensure_full_index_unaudited(the_repository->index);
 	for (i = 0; i < the_repository->index->cache_nr; i++) {
 		const struct cache_entry *ce = the_repository->index->cache[i];
 		if (!ce_stage(ce))
@@ -88,7 +88,7 @@ int cmd_merge_index(int argc, const char **argv, const char *prefix UNUSED)
 	repo_read_index(the_repository);
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(the_repository->index);
+	ensure_full_index_unaudited(the_repository->index);
 
 	i = 1;
 	if (!strcmp(argv[i], "-o")) {

builtin/read-tree.c

@@ -224,7 +224,8 @@ int cmd_read_tree(int argc, const char **argv, const char *cmd_prefix)
 		setup_work_tree();
 
 	if (opts.skip_sparse_checkout)
-		ensure_full_index(the_repository->index);
+		ensure_full_index_with_reason(the_repository->index,
+					      "read-tree");
 
 	if (opts.merge) {
 		switch (stage - 1) {

builtin/reset.c

@@ -259,7 +259,8 @@ static int read_from_tree(const struct pathspec *pathspec,
 	opt.add_remove = diff_addremove;
 
 	if (pathspec->nr && pathspec_needs_expanded_index(the_repository->index, pathspec))
-		ensure_full_index(the_repository->index);
+		ensure_full_index_with_reason(the_repository->index,
+					      "reset pathspec");
 
 	if (do_diff_cache(tree_oid, &opt))
 		return 1;

builtin/rm.c

@@ -307,7 +307,8 @@ int cmd_rm(int argc, const char **argv, const char *prefix)
 	seen = xcalloc(pathspec.nr, 1);
 
 	if (pathspec_needs_expanded_index(the_repository->index, &pathspec))
-		ensure_full_index(the_repository->index);
+		ensure_full_index_with_reason(the_repository->index,
+					      "rm pathspec");
 
 	for (i = 0; i < the_repository->index->cache_nr; i++) {
 		const struct cache_entry *ce = the_repository->index->cache[i];

builtin/sparse-checkout.c

@@ -204,7 +204,8 @@ static void clean_tracked_sparse_directories(struct repository *r)
 	strbuf_release(&path);
 
 	if (was_full)
-		ensure_full_index(r->index);
+		ensure_full_index_with_reason(r->index,
+				"sparse-checkout:was full");
 }
 
 static int update_working_directory(struct pattern_list *pl)
@@ -435,7 +436,8 @@ static int update_modes(int *cone_mode, int *sparse_index)
 		the_repository->index->updated_workdir = 1;
 
 		if (!*sparse_index)
-			ensure_full_index(the_repository->index);
+			ensure_full_index_with_reason(the_repository->index,
+				"sparse-checkout:disabling sparse index");
 	}
 
 	return 0;

builtin/stash.c

@@ -1549,7 +1549,7 @@ static int do_push_stash(const struct pathspec *ps, const char *stash_msg, int q
 		char *ps_matched = xcalloc(ps->nr, 1);
 
 		/* TODO: audit for interaction with sparse-index. */
-		ensure_full_index(the_repository->index);
+		ensure_full_index_unaudited(the_repository->index);
 		for (i = 0; i < the_repository->index->cache_nr; i++)
 			ce_path_match(the_repository->index, the_repository->index->cache[i], ps,
 				      ps_matched);

builtin/submodule--helper.c

@@ -3321,7 +3321,7 @@ static void die_on_index_match(const char *path, int force)
 		char *ps_matched = xcalloc(ps.nr, 1);
 
 		/* TODO: audit for interaction with sparse-index. */
-		ensure_full_index(the_repository->index);
+		ensure_full_index_unaudited(the_repository->index);
 
 		/*
 		 * Since there is only one pathspec, we just need to

builtin/update-index.c

@@ -712,7 +712,9 @@ static int do_reupdate(const char **paths,
 		 * to process each path individually
 		 */
 		if (S_ISSPARSEDIR(ce->ce_mode)) {
-			ensure_full_index(the_repository->index);
+			const char *fmt = "update-index:modified sparse dir '%s'";
+			ensure_full_index_with_reason(the_repository->index,
+						      fmt, ce->name);
 			goto redo;
 		}
 

entry.c

@@ -451,7 +451,7 @@ static void mark_colliding_entries(const struct checkout *state,
 	ce->ce_flags |= CE_MATCHED;
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(state->istate);
+	ensure_full_index_unaudited(state->istate);
 	for (i = 0; i < state->istate->cache_nr; i++) {
 		struct cache_entry *dup = state->istate->cache[i];
 

merge-ort.c

@@ -4532,7 +4532,8 @@ static int record_conflicted_index_entries(struct merge_options *opt)
 	 */
 	strmap_for_each_entry(&opt->priv->conflicted, &iter, e) {
 		if (!path_in_sparse_checkout(e->key, index)) {
-			ensure_full_index(index);
+			const char *fmt = "merge-ort: path outside sparse checkout (%s)";
+			ensure_full_index_with_reason(index, fmt, e->key);
 			break;
 		}
 	}

merge-recursive.c

@@ -539,7 +539,7 @@ static struct string_list *get_unmerged(struct index_state *istate)
 	string_list_init_dup(unmerged);
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(istate);
+	ensure_full_index_unaudited(istate);
 	for (i = 0; i < istate->cache_nr; i++) {
 		struct string_list_item *item;
 		struct stage_data *e;

read-cache.c

@@ -553,7 +553,9 @@ static int index_name_stage_pos(struct index_state *istate,
 		if (S_ISSPARSEDIR(ce->ce_mode) &&
 		    ce_namelen(ce) < namelen &&
 		    !strncmp(name, ce->name, ce_namelen(ce))) {
-			ensure_full_index(istate);
+			const char *fmt = "searching for '%s' and found parent dir '%s'";
+			ensure_full_index_with_reason(istate, fmt,
+						      name, ce->name);
 			return index_name_stage_pos(istate, name, namelen, stage, search_mode);
 		}
 	}
@@ -2373,7 +2375,7 @@ int do_read_index(struct index_state *istate, const char *path, int must_exist)
 	 */
 	prepare_repo_settings(istate->repo);
 	if (istate->repo->settings.command_requires_full_index)
-		ensure_full_index(istate);
+		ensure_full_index_with_reason(istate, "incompatible builtin");
 	else
 		ensure_correct_sparsity(istate);
 
@@ -2585,7 +2587,7 @@ int repo_index_has_changes(struct repository *repo,
 		return opt.flags.has_changes != 0;
 	} else {
 		/* TODO: audit for interaction with sparse-index. */
-		ensure_full_index(istate);
+		ensure_full_index_unaudited(istate);
 		for (i = 0; sb && i < istate->cache_nr; i++) {
 			if (i)
 				strbuf_addch(sb, ' ');
@@ -3242,7 +3244,7 @@ static int do_write_locked_index(struct index_state *istate,
 				   "%s", get_lock_file_path(lock));
 
 	if (was_full)
-		ensure_full_index(istate);
+		ensure_full_index_with_reason(istate, "re-expanding after write");
 
 	if (ret)
 		return ret;
@@ -3346,7 +3348,7 @@ static int write_shared_index(struct index_state *istate,
 				   the_repository, "%s", get_tempfile_path(*temp));
 
 	if (was_full)
-		ensure_full_index(istate);
+		ensure_full_index_with_reason(istate, "re-expanding after write");
 
 	if (ret)
 		return ret;
@@ -3896,7 +3898,7 @@ void overlay_tree_on_index(struct index_state *istate,
 
 	/* Hoist the unmerged entries up to stage #3 to make room */
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(istate);
+	ensure_full_index_unaudited(istate);
 	for (i = 0; i < istate->cache_nr; i++) {
 		struct cache_entry *ce = istate->cache[i];
 		if (!ce_stage(ce))

repository.c

@@ -393,7 +393,7 @@ int repo_read_index(struct repository *repo)
 
 	prepare_repo_settings(repo);
 	if (repo->settings.command_requires_full_index)
-		ensure_full_index(repo->index);
+		ensure_full_index_with_reason(repo->index, "incompatible builtin");
 
 	/*
 	 * If sparse checkouts are in use, check whether paths with the

resolve-undo.c

@@ -160,7 +160,7 @@ void unmerge_index(struct index_state *istate, const struct pathspec *pathspec,
 		return;
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(istate);
+	ensure_full_index_unaudited(istate);
 
 	for_each_string_list_item(item, istate->resolve_undo) {
 		const char *path = item->string;

revision.c

@@ -1828,7 +1828,7 @@ static void do_add_index_objects_to_pending(struct rev_info *revs,
 	int i;
 
 	/* TODO: audit for interaction with sparse-index. */
-	ensure_full_index(istate);
+	ensure_full_index_unaudited(istate);
 	for (i = 0; i < istate->cache_nr; i++) {
 		struct cache_entry *ce = istate->cache[i];
 		struct blob *blob;

sequencer.c

@@ -795,7 +795,7 @@ static int do_recursive_merge(struct repository *r,
 		merge_switch_to_result(&o, head_tree, &result, 1, show_output);
 		clean = result.clean;
 	} else {
-		ensure_full_index(r->index);
+		ensure_full_index_with_reason(r->index, "non-ort merge strategy");
 		clean = merge_trees(&o, head_tree, next_tree, base_tree);
 		if (is_rebase_i(opts) && clean <= 0)
 			fputs(o.obuf.buf, stdout);
@@ -2567,7 +2567,7 @@ static int read_and_refresh_cache(struct repository *r,
 	 * expand the sparse index.
 	 */
 	if (opts->strategy && strcmp(opts->strategy, "ort"))
-		ensure_full_index(r->index);
+		ensure_full_index_with_reason(r->index, "non-ort merge strategy");
 	return 0;
 }
 

sparse-index.c

@@ -456,6 +456,24 @@ void ensure_full_index(struct index_state *istate)
 	expand_index(istate, NULL);
 }
 
+void ensure_full_index_with_reason(struct index_state *istate,
+				   const char *fmt, ...)
+{
+	va_list ap;
+	struct strbuf why = STRBUF_INIT;
+	if (!istate)
+		BUG("ensure_full_index_with_reason() must get an index!");
+	if (istate->sparse_index == INDEX_EXPANDED)
+		return;
+
+	va_start(ap, fmt);
+	strbuf_vaddf(&why, fmt, ap);
+	trace2_data_string("sparse-index", istate->repo, "expansion-reason", why.buf);
+	va_end(ap);
+	strbuf_release(&why);
+	ensure_full_index(istate);
+}
+
 void ensure_correct_sparsity(struct index_state *istate)
 {
 	/*
@@ -465,7 +483,8 @@ void ensure_correct_sparsity(struct index_state *istate)
 	if (is_sparse_index_allowed(istate, 0))
 		convert_to_sparse(istate, 0);
 	else
-		ensure_full_index(istate);
+		ensure_full_index_with_reason(istate,
+					      "sparse index not allowed");
 }
 
 struct path_found_data {
@@ -613,6 +632,8 @@ static int clear_skip_worktree_from_present_files_sparse(struct index_state *ist
 			if (path_found(ce->name, &data)) {
 				if (S_ISSPARSEDIR(ce->ce_mode)) {
 					to_restart = 1;
+					trace2_data_string("sparse-index", istate->repo,
+							   "skip-worktree sparsedir", ce->name);
 					break;
 				}
 				ce->ce_flags &= ~CE_SKIP_WORKTREE;
@@ -668,7 +689,8 @@ void clear_skip_worktree_from_present_files(struct index_state *istate)
 		return;
 
 	if (clear_skip_worktree_from_present_files_sparse(istate)) {
-		ensure_full_index(istate);
+		ensure_full_index_with_reason(istate,
+			"failed to clear skip-worktree while sparse");
 		clear_skip_worktree_from_present_files_full(istate);
 	}
 }
@@ -731,7 +753,9 @@ void expand_to_path(struct index_state *istate,
 			 * in the index, perhaps it exists within this
 			 * sparse-directory.  Expand accordingly.
 			 */
-			ensure_full_index(istate);
+			const char *fmt = "found index entry for '%s'";
+			ensure_full_index_with_reason(istate, fmt,
+						      path_mutable.buf);
 			break;
 		}
 

sparse-index.h

@@ -1,6 +1,8 @@
 #ifndef SPARSE_INDEX_H__
 #define SPARSE_INDEX_H__
 
+#include "strbuf.h"
+
 struct index_state;
 #define SPARSE_INDEX_MEMORY_ONLY (1 << 0)
 int is_sparse_index_allowed(struct index_state *istate, int flags);
@@ -39,4 +41,16 @@ void expand_index(struct index_state *istate, struct pattern_list *pl);
 
 void ensure_full_index(struct index_state *istate);
 
+/**
+ * If there is a clear reason why the sparse index is being expanded, then
+ * trace the information for why the expansion is occurring.
+ */
+void ensure_full_index_with_reason(struct index_state *istate,
+				   const char *fmt,
+				   ...);
+
+#define ensure_full_index_unaudited(i) \
+	ensure_full_index_with_reason((i), \
+		"unaudited call (%s.%d)", __FILE__, __LINE__);
+
 #endif

t/t1092-sparse-checkout-compatibility.sh

@@ -2448,4 +2448,20 @@ test_expect_success 'advice.sparseIndexExpanded' '
 	grep "The sparse index is expanding to a full index" err
 '
 
+test_expect_success 'ensure_full_index_with_reason' '
+	init_repos &&
+
+	GIT_TRACE2_EVENT="$(pwd)/ls-files-trace" \
+		git -C sparse-index ls-files --no-sparse HEAD &&
+	test_trace2_data "sparse-index" "expansion-reason" "ls-files" <ls-files-trace &&
+
+	mkdir -p sparse-index/folder2 &&
+	echo >sparse-index/folder2/a &&
+	GIT_TRACE2_EVENT="$(pwd)/status-trace" \
+		git -C sparse-index status &&
+	test_trace2_data "sparse-index" "skip-worktree sparsedir" "folder2/" <status-trace &&
+	test_trace2_data "sparse-index" "expansion-reason" \
+		"failed to clear skip-worktree while sparse" <status-trace
+'
+
 test_done

unpack-trees.c

@@ -1887,8 +1887,10 @@ static void update_sparsity_for_prefix(const char *prefix,
 	 *   the 'ensure_full_index(...)' below.
 	 */
 	if (!path_in_cone_mode_sparse_checkout(ce_prefix.buf, istate) &&
-	    index_name_pos(istate, ce_prefix.buf, ce_prefix.len) >= 0)
-		ensure_full_index(istate);
+	    index_name_pos(istate, ce_prefix.buf, ce_prefix.len) >= 0) {
+		const char *fmt = "could not find '%s' in index";
+		ensure_full_index_with_reason(istate, fmt, ce_prefix.buf);
+	}
 
 	strbuf_release(&ce_prefix);
 }
@@ -1932,9 +1934,9 @@ int unpack_trees(unsigned len, struct tree_desc *t, struct unpack_trees_options
 
 	prepare_repo_settings(repo);
 	if (repo->settings.command_requires_full_index) {
-		ensure_full_index(o->src_index);
+		ensure_full_index_with_reason(o->src_index, "incompatible builtin");
 		if (o->dst_index)
-			ensure_full_index(o->dst_index);
+			ensure_full_index_with_reason(o->dst_index, "incompatible builtin");
 	}
 
 	if (o->reset == UNPACK_RESET_OVERWRITE_UNTRACKED &&