git/list[1] front-page[2] threads[3] people[4] search[5] about
 

[PATCH v9 18/19] trace: measure where the time is spent in the index-heavy operations

From
David Turner <dturner@twopensource.com>
Date
May 9, 2016, 20:48 UTC
Message-ID
<1462826929-7567-19-git-send-email-dturner@twopensource.com>
In-Reply-To
<1462826929-7567-1-git-send-email-dturner@twopensource.com>
From: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>

All the known heavy code blocks are measured (except object database access). This should help identify if an optimization is effective or not. An unoptimized git-status would give something like below (92% of time is accounted). To sum up the effort of making git scale better:

 - read cache line is being addressed by index-helper
 - preload/refresh index by watchman
 - read packed refs by lmdb backend
 - diff-index by rebuilding cache-tree
 - read directory by untracked cache and watchman
 - write index by split index
 - name hash potientially by index-helper

read-cache.c:2075 performance: 0.004058570 s: read cache .../index preload-index.c:104 performance: 0.004419864 s: preload index read-cache.c:1265 performance: 0.000185224 s: refresh index refs/files-backend.c:1100 performance: 0.001935788 s: read packed refs diff-lib.c:240 performance: 0.000144132 s: diff-files diff-lib.c:506 performance: 0.013592000 s: diff-index name-hash.c:128 performance: 0.000614177 s: initialize name hash dir.c:2030 performance: 0.015814103 s: read directory read-cache.c:2565 performance: 0.004052343 s: write index, changed mask = 2 trace.c:420 performance: 0.048365509 s: git command: './git' 'status'

Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com>
Signed-off-by: David Turner <dturner@twopensource.com>
---
 diff-lib.c           |  4 ++++
 dir.c                |  2 ++
 name-hash.c          |  2 ++
 preload-index.c      |  2 ++
 read-cache.c         | 11 +++++++++++
 refs/files-backend.c |  2 ++
 6 files changed, 23 insertions(+)
diff --git a/diff-lib.c b/diff-lib.c
index bc49c70..7af7f9a 100644
--- a/diff-lib.c
+++ b/diff-lib.c
@@ -90,6 +90,7 @@ int run_diff_files(struct rev_info *revs, unsigned int option)
 	int diff_unmerged_stage = revs->max_count;
 	unsigned ce_option = ((option & DIFF_RACY_IS_MODIFIED)
 			      ? CE_MATCH_RACY_IS_DIRTY : 0);
+	uint64_t start = getnanotime();
 
 	diff_set_mnemonic_prefix(&revs->diffopt, "i/", "w/");
 
@@ -236,6 +237,7 @@ int run_diff_files(struct rev_info *revs, unsigned int option)
 	}
 	diffcore_std(&revs->diffopt);
 	diff_flush(&revs->diffopt);
+	trace_performance_since(start, "diff-files");
 	return 0;
 }
 
@@ -491,6 +493,7 @@ static int diff_cache(struct rev_info *revs,
 int run_diff_index(struct rev_info *revs, int cached)
 {
 	struct object_array_entry *ent;
+	uint64_t start = getnanotime();
 
 	ent = revs->pending.objects;
 	if (diff_cache(revs, ent->item->oid.hash, ent->name, cached))
@@ -500,6 +503,7 @@ int run_diff_index(struct rev_info *revs, int cached)
 	diffcore_fix_diff_index(&revs->diffopt);
 	diffcore_std(&revs->diffopt);
 	diff_flush(&revs->diffopt);
+	trace_performance_since(start, "diff-index");
 	return 0;
 }
 
diff --git a/dir.c b/dir.c
index 5058b29..c56a8b9 100644
--- a/dir.c
+++ b/dir.c
@@ -2183,6 +2183,7 @@ int read_directory(struct dir_struct *dir, const char *path, int len, const stru
 {
 	struct path_simplify *simplify;
 	struct untracked_cache_dir *untracked;
+	uint64_t start = getnanotime();
 
 	/*
 	 * Check out create_simplify()
@@ -2224,6 +2225,7 @@ int read_directory(struct dir_struct *dir, const char *path, int len, const stru
 	free_simplify(simplify);
 	qsort(dir->entries, dir->nr, sizeof(struct dir_entry *), cmp_name);
 	qsort(dir->ignored, dir->ignored_nr, sizeof(struct dir_entry *), cmp_name);
+	trace_performance_since(start, "read directory %.*s", len, path);
 	if (dir->untracked) {
 		static struct trace_key trace_untracked_stats = TRACE_KEY_INIT(UNTRACKED_STATS);
 		trace_printf_key(&trace_untracked_stats,
diff --git a/name-hash.c b/name-hash.c
index 6d9f23e..b3966d8 100644
--- a/name-hash.c
+++ b/name-hash.c
@@ -115,6 +115,7 @@ static int cache_entry_cmp(const struct cache_entry *ce1,
 static void lazy_init_name_hash(struct index_state *istate)
 {
 	int nr;
+	uint64_t start = getnanotime();
 
 	if (istate->name_hash_initialized)
 		return;
@@ -124,6 +125,7 @@ static void lazy_init_name_hash(struct index_state *istate)
 	for (nr = 0; nr < istate->cache_nr; nr++)
 		hash_index_entry(istate, istate->cache[nr]);
 	istate->name_hash_initialized = 1;
+	trace_performance_since(start, "initialize name hash");
 }
 
 void add_name_hash(struct index_state *istate, struct cache_entry *ce)
diff --git a/preload-index.c b/preload-index.c
index c1fe3a3..7bb4809 100644
--- a/preload-index.c
+++ b/preload-index.c
@@ -72,6 +72,7 @@ static void preload_index(struct index_state *index,
 {
 	int threads, i, work, offset;
 	struct thread_data data[MAX_PARALLEL];
+	uint64_t start = getnanotime();
 
 	if (!core_preload_index)
 		return;
@@ -100,6 +101,7 @@ static void preload_index(struct index_state *index,
 		if (pthread_join(p->pthread, NULL))
 			die("unable to join threaded lstat");
 	}
+	trace_performance_since(start, "preload index");
 }
 #endif
 
diff --git a/read-cache.c b/read-cache.c
index ebbcb7f..c547b0b 100644
--- a/read-cache.c
+++ b/read-cache.c
@@ -1189,6 +1189,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 	const char *typechange_fmt;
 	const char *added_fmt;
 	const char *unmerged_fmt;
+	uint64_t start = getnanotime();
 
 	modified_fmt = (in_porcelain ? "M\t%s\n" : "%s: needs update\n");
 	deleted_fmt = (in_porcelain ? "D\t%s\n" : "%s: needs update\n");
@@ -1263,6 +1264,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,
 
 		replace_index_entry(istate, i, new);
 	}
+	trace_performance_since(start, "refresh index");
 	return has_errors;
 }
 
@@ -2086,12 +2088,15 @@ int read_index_from(struct index_state *istate, const char *path)
 {
 	struct split_index *split_index;
 	int ret;
+	uint64_t start;
 
 	/* istate->initialized covers both .git/index and .git/sharedindex.xxx */
 	if (istate->initialized)
 		return istate->cache_nr;
 
+	start = getnanotime();
 	ret = do_read_index(istate, path, 0);
+	trace_performance_since(start, "read cache %s", path);
 
 	split_index = istate->split_index;
 	if (!split_index || is_null_sha1(split_index->base_sha1)) {
@@ -2106,6 +2111,7 @@ int read_index_from(struct index_state *istate, const char *path)
 	split_index->base->keep_mmap = istate->keep_mmap;
 	split_index->base->to_shm    = istate->to_shm;
 	split_index->base->from_shm  = istate->from_shm;
+	start = getnanotime();
 	ret = do_read_index(split_index->base,
 			    git_path("sharedindex.%s",
 				     sha1_to_hex(split_index->base_sha1)), 1);
@@ -2117,6 +2123,9 @@ int read_index_from(struct index_state *istate, const char *path)
 		    sha1_to_hex(split_index->base->sha1));
 	merge_base_index(istate);
 	post_read_index_from(istate);
+	trace_performance_since(start, "read cache %s",
+				git_path("sharedindex.%s",
+					 sha1_to_hex(split_index->base_sha1)));
 
 done:
 	if (ret > 0 && istate->from_shm && istate->last_update)
@@ -2462,6 +2471,7 @@ static int do_write_index(struct index_state *istate, int newfd,
 	struct stat st;
 	struct strbuf previous_name_buf = STRBUF_INIT, *previous_name;
 	int watchman = 0;
+	uint64_t start = getnanotime();
 
 	for (i = removed = extended = 0; i < entries; i++) {
 		if (cache[i]->ce_flags & CE_REMOVE)
@@ -2582,6 +2592,7 @@ static int do_write_index(struct index_state *istate, int newfd,
 		return -1;
 	istate->timestamp.sec = (unsigned int)st.st_mtime;
 	istate->timestamp.nsec = ST_MTIME_NSEC(st);
+	trace_performance_since(start, "write index, changed mask = %x", istate->cache_changed);
 	return 0;
 }
 
diff --git a/refs/files-backend.c b/refs/files-backend.c
index 81f68f8..57571ce 100644
--- a/refs/files-backend.c
+++ b/refs/files-backend.c
@@ -1048,6 +1048,7 @@ static void read_packed_refs(FILE *f, struct ref_dir *dir)
 	struct ref_entry *last = NULL;
 	struct strbuf line = STRBUF_INIT;
 	enum { PEELED_NONE, PEELED_TAGS, PEELED_FULLY } peeled = PEELED_NONE;
+	uint64_t start = getnanotime();
 
 	while (strbuf_getwholeline(&line, f, '\n') != EOF) {
 		unsigned char sha1[20];
@@ -1096,6 +1097,7 @@ static void read_packed_refs(FILE *f, struct ref_dir *dir)
 	}
 
 	strbuf_release(&line);
+	trace_performance_since(start, "read packed refs");
 }
 
 /*
-- 
2.4.2.767.g62658d5-twtrsrc
Previous: David TurnerNext: David Turner
Message 24 of 39 in “index-helper/watchman”
  1. 00/19 index-helper/watchmanDavid Turner, May 9, 2016
  2. 01/19 read-cache.c: fix constness of verify_hdr()David Turner, May 9, 2016
  3. 02/19 read-cache: allow to keep mmap'd memory after readingDavid Turner, May 9, 2016
  4. 03/19 index-helper: new daemon for caching index and related stuffDavid Turner, May 9, 2016
  5. SZEDER GáborMay 10, 2016
  6. Duy NguyenMay 10, 2016
  7. SZEDER GáborMay 10, 2016
  8. Duy NguyenMay 10, 2016
  9. David TurnerMay 10, 2016
  10. 04/19 index-helper: add --strictDavid Turner, May 9, 2016
  11. 05/19 index-helper: log warningsDavid Turner, May 9, 2016
  12. 06/19 daemonize(): set a flag before exiting the main processDavid Turner, May 9, 2016
  13. 07/19 index-helper: add --detachDavid Turner, May 9, 2016
  14. 08/19 read-cache: add watchman 'WAMA' extensionDavid Turner, May 9, 2016
  15. 09/19 watchman: support watchman to reduce index refresh costDavid Turner, May 9, 2016
  16. 10/19 index-helper: use watchman to avoid refreshing index with lstat()David Turner, May 9, 2016
  17. 11/19 update-index: enable/disable watchman supportDavid Turner, May 9, 2016
  18. 12/19 unpack-trees: preserve index extensionsDavid Turner, May 9, 2016
  19. 13/19 watchman: add a config option to enable the extensionDavid Turner, May 9, 2016
  20. 14/19 index-helper: kill modeDavid Turner, May 9, 2016
  21. 15/19 index-helper: don't run if already runningDavid Turner, May 9, 2016
  22. 16/19 index-helper: autorun modeDavid Turner, May 9, 2016
  23. 17/19 index-helper: optionally automatically runDavid Turner, May 9, 2016
  24. 18/19 trace: measure where the time is spent in the index-heavy operationsDavid Turner, May 9, 2016
  25. 19/19 untracked-cache: config optionDavid Turner, May 9, 2016
  26. Junio C HamanoMay 9, 2016
  27. David TurnerMay 9, 2016
  28. Junio C HamanoMay 9, 2016
  29. Junio C HamanoMay 9, 2016
  30. David TurnerMay 9, 2016
  31. Ramsay JonesMay 9, 2016
  32. Duy NguyenMay 10, 2016
  33. Duy NguyenMay 10, 2016
  34. Dennis KaarsemakerMay 10, 2016
  35. Dennis KaarsemakerMay 10, 2016
  36. Dennis KaarsemakerMay 10, 2016
  37. Ramsay JonesMay 10, 2016
  38. Junio C HamanoMay 10, 2016
  39. Ramsay JonesMay 10, 2016

Read the whole thread, see it on lore, or plain text.

$ cat FOOTERMessages come from the public archive at lore.kernel.org/git, fetched every hour. The front page is chosen and written each morning by an AI editor and can be wrong; the threads themselves are the record. About and API. For agents: an MCP server at https://gitlist.dev/mcp, and any thread, story or person page as Markdown by adding .md to its URL (or sending Accept: text/markdown). Details in /llms.txt.