{"thread":{"id":"36994","subject":"Git-status / preload_index() performance","startedAt":"2014-06-24T22:52:25Z","lastAt":"2014-07-26T10:33:27Z","messageCount":9,"participants":["Karsten Blees","David Turner","Duy Nguyen"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"244945","messageId":"53AA0129.1080109@gmail.com","threadId":"36994","inReplyTo":null,"subject":"Git-status / preload_index() performance","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-06-24T22:52:25Z","receivedAt":"2014-06-24T22:52:25Z","isPatch":false,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Putting the new trace_performance functions to good use, here are a few observations about git-status performance.\n\nComes with three patches (mostly independent, not a patch series!):\n\n * [PATCH] preload-index: optimize for sequential IO\n   Improves preload-index performance, should apply anywhere.\n\n * [PATCH (experimental)] preload-index: make parallel IO configurable\n   For anyone who'd like to play around with different parallel IO settings. Applies on top of the first patch.\n\n * [PATCH (performance tracing)] test git-status performance\n   Used to generate the measurements at the bottom, applies on top of the performance tracing topic, e.g. pu.\n\n\nHere's a rough break down of overall 'git-status -uno' performance (hot cache, preloadIndex, single HD) (see measurements [D] and [F] below):\n\n\t20% (~95 ms)  parse options and config files\n  20% (~95 ms)  preload index\n  55% (~275 ms) unpack HEAD tree\n\nWhat surprised me was that we spend a lot of time parsing options and config files. Tanay's current config-cache topic may fix this (haven't checked though).\n\nEven more time is spent unpacking the HEAD tree, even with hot cache (repacking with depth 10 reduces this to ~250ms, on SSD its just 7ms). Perhaps caching the HEAD tree in an index extension could help here?\n\n\nLooking at preload_index() in more detail revealed that the background threads don't really run in parallel. In the cold cache case [C], some threads finish >10 s earlier than the last one. In the hot cache case [D], the last thread starts long after the first has finished (average thread run time is 25 ms, but the whole thing takes >100 ms). This is fixed in the first patch (although with hot cache, some threads exit immediately without doing anything, so starting 20 threads seems to be slower than lstat()ing 200k files).\n\nAnother issue with preload_index() in the cold cache case is the IO pattern. File systems are typically organized by directories, as is git's index. Reading from up to 20 different locations in parallel isn't exactly optimal, thus preload_index() with cold cache [C] is actually slower than lstat()ing the files sequentially in refresh_index() [A]. This is also fixed in the first patch.\n\nThe second patch makes parallel IO configurable (independent of the thread count), in case anyone is eager to play around with this (I got best results with PARALLEL_IO == 1, i.e. the same as what the first patch does).\n\n\nBtw, I got similar results on Windows (just a tad slower). However, the current fscache implementation sucks with multi-threaded sequential directory scans. This is fixed in https://github.com/msysgit/git/pull/205\n\nCheers,\nKarsten\n\n\n=== Measurements ===\n\nTest environment:\n- Debian Linux\n- Core i7 960 @2.8 GHz (quad core HT)\n- WD VelociRaptor 300G\n- WebKit, compressed with depth 50\n- GIT_TRACE_PERFORMANCE=1 git status -s -uno\n\n--- A. cold cache, preloadIndex = false ---\n21:48:51.846358 builtin/commit.c:1374   performance: 0.373945122 s: cmd_status:setup\n21:48:51.847107 preload-index.c:115     performance: 0.000000970 s: read_index_preload\n21:49:17.464247 read-cache.c:1226       performance: 25.616986865 s: refresh_index\n21:49:17.467816 builtin/commit.c:1385   performance: 0.003506054 s: cmd_status:update_index\n21:49:17.479184 wt-status.c:630         performance: 0.005727824 s: wt_status_collect_changes_worktree\n21:49:26.887034 wt-status.c:638         performance: 9.407759653 s: wt_status_collect_changes_index\n21:49:26.887183 wt-status.c:643         performance: 0.000002555 s: wt_status_collect_untracked\n21:49:26.887274 trace.c:414             performance: 35.438535209 s: git command: 'git' 'status' '-s' '-uno'\n\n--- B. hot cache, preloadIndex = false ---\n21:50:06.756099 builtin/commit.c:1374   performance: 0.096772167 s: cmd_status:setup\n21:50:06.756294 preload-index.c:115     performance: 0.000000842 s: read_index_preload\n21:50:07.009081 read-cache.c:1226       performance: 0.252756680 s: refresh_index\n21:50:07.012212 builtin/commit.c:1385   performance: 0.002993493 s: cmd_status:update_index\n21:50:07.017863 wt-status.c:630         performance: 0.005366752 s: wt_status_collect_changes_worktree\n21:50:07.304434 wt-status.c:638         performance: 0.286400219 s: wt_status_collect_changes_index\n21:50:07.304506 wt-status.c:643         performance: 0.000002140 s: wt_status_collect_untracked\n21:50:07.304562 trace.c:414             performance: 0.645498343 s: git command: 'git' 'status' '-s' '-uno'\n\n--- C. cold cache, preloadIndex = true (original) ---\n21:37:56.446451 builtin/commit.c:1374   performance: 0.370568378 s: cmd_status:setup\n21:38:13.742558 preload-index.c:68      performance: 17.294946043 s: preload_thread\n21:38:18.271304 preload-index.c:68      performance: 21.822004315 s: preload_thread\n21:38:18.675936 preload-index.c:68      performance: 22.226297259 s: preload_thread\n21:38:19.631832 preload-index.c:68      performance: 23.182681753 s: preload_thread\n21:38:19.647241 preload-index.c:68      performance: 23.197129488 s: preload_thread\n21:38:20.706758 preload-index.c:68      performance: 24.258704977 s: preload_thread\n21:38:20.716336 preload-index.c:68      performance: 24.267554747 s: preload_thread\n21:38:21.360835 preload-index.c:68      performance: 24.912336936 s: preload_thread\n21:38:21.950539 preload-index.c:68      performance: 25.501558541 s: preload_thread\n21:38:22.303187 preload-index.c:68      performance: 25.855297857 s: preload_thread\n21:38:22.401046 preload-index.c:68      performance: 25.953550575 s: preload_thread\n21:38:22.900621 preload-index.c:68      performance: 26.450856089 s: preload_thread\n21:38:23.152811 preload-index.c:68      performance: 26.705084749 s: preload_thread\n21:38:23.798287 preload-index.c:68      performance: 27.348779464 s: preload_thread\n21:38:23.902508 preload-index.c:68      performance: 27.454145935 s: preload_thread\n21:38:24.105539 preload-index.c:68      performance: 27.655335680 s: preload_thread\n21:38:24.224639 preload-index.c:68      performance: 27.774589132 s: preload_thread\n21:38:24.308084 preload-index.c:68      performance: 27.859839181 s: preload_thread\n21:38:24.696634 preload-index.c:68      performance: 28.246249590 s: preload_thread\n21:38:25.126601 preload-index.c:68      performance: 28.676157964 s: preload_thread\n21:38:25.126910 preload-index.c:115     performance: 28.679619307 s: read_index_preload\n21:38:25.135398 read-cache.c:1226       performance: 0.008454608 s: refresh_index\n21:38:25.138316 builtin/commit.c:1385   performance: 0.002882190 s: cmd_status:update_index\n21:38:25.158006 wt-status.c:630         performance: 0.006232814 s: wt_status_collect_changes_worktree\n21:38:34.540506 wt-status.c:638         performance: 9.382413445 s: wt_status_collect_changes_index\n21:38:34.540656 wt-status.c:643         performance: 0.000002382 s: wt_status_collect_untracked\n21:38:34.540718 trace.c:414             performance: 38.488630426 s: git command: 'git' 'status' '-s' '-uno'\n\n--- D. hot cache, preloadIndex = true (original) ---\n21:42:00.212503 builtin/commit.c:1374   performance: 0.095433165 s: cmd_status:setup\n21:42:00.228933 preload-index.c:68      performance: 0.015721331 s: preload_thread\n21:42:00.231618 preload-index.c:68      performance: 0.018584533 s: preload_thread\n21:42:00.240873 preload-index.c:68      performance: 0.028002477 s: preload_thread\n21:42:00.243997 preload-index.c:68      performance: 0.030051421 s: preload_thread\n21:42:00.247607 preload-index.c:68      performance: 0.033567965 s: preload_thread\n21:42:00.254185 preload-index.c:68      performance: 0.015472710 s: preload_thread\n21:42:00.256297 preload-index.c:68      performance: 0.041539430 s: preload_thread\n21:42:00.258719 preload-index.c:68      performance: 0.015969134 s: preload_thread\n21:42:00.266561 preload-index.c:68      performance: 0.019649941 s: preload_thread\n21:42:00.268836 preload-index.c:68      performance: 0.050104808 s: preload_thread\n21:42:00.276642 preload-index.c:68      performance: 0.017524942 s: preload_thread\n21:42:00.286878 preload-index.c:68      performance: 0.029321929 s: preload_thread\n21:42:00.287704 preload-index.c:68      performance: 0.032922849 s: preload_thread\n21:42:00.290427 preload-index.c:68      performance: 0.023335902 s: preload_thread\n21:42:00.299536 preload-index.c:68      performance: 0.030398197 s: preload_thread\n21:42:00.300145 preload-index.c:68      performance: 0.023044898 s: preload_thread\n21:42:00.305255 preload-index.c:68      performance: 0.014311763 s: preload_thread\n21:42:00.305593 preload-index.c:68      performance: 0.018377127 s: preload_thread\n21:42:00.313995 preload-index.c:68      performance: 0.026190281 s: preload_thread\n21:42:00.316405 preload-index.c:68      performance: 0.016561475 s: preload_thread\n21:42:00.316610 preload-index.c:115     performance: 0.103935355 s: read_index_preload\n21:42:00.324869 read-cache.c:1226       performance: 0.008188349 s: refresh_index\n21:42:00.327998 builtin/commit.c:1385   performance: 0.003042783 s: cmd_status:update_index\n21:42:00.333993 wt-status.c:630         performance: 0.005798696 s: wt_status_collect_changes_worktree\n21:42:00.611613 wt-status.c:638         performance: 0.277536014 s: wt_status_collect_changes_index\n21:42:00.611687 wt-status.c:643         performance: 0.000002299 s: wt_status_collect_untracked\n21:42:00.611747 trace.c:414             performance: 0.494946405 s: git command: 'git' 'status' '-s' '-uno'\n\n--- E. cold cache, preloadIndex = true (patched) ---\n22:06:56.232746 builtin/commit.c:1374   performance: 0.370093911 s: cmd_status:setup\n22:07:16.102354 preload-index.c:82      performance: 19.867838450 s: preload_thread\n22:07:16.104169 preload-index.c:82      performance: 19.868153951 s: preload_thread\n22:07:16.137857 preload-index.c:82      performance: 19.902306388 s: preload_thread\n22:07:16.182094 preload-index.c:82      performance: 19.946227999 s: preload_thread\n22:07:16.192515 preload-index.c:82      performance: 19.958357027 s: preload_thread\n22:07:16.230063 preload-index.c:82      performance: 19.993785729 s: preload_thread\n22:07:16.326531 preload-index.c:82      performance: 20.089808984 s: preload_thread\n22:07:16.487604 preload-index.c:82      performance: 20.250688054 s: preload_thread\n22:07:16.528616 preload-index.c:82      performance: 20.291710330 s: preload_thread\n22:07:16.830113 preload-index.c:82      performance: 20.595193324 s: preload_thread\n22:07:16.832527 preload-index.c:82      performance: 20.596083545 s: preload_thread\n22:07:16.878497 preload-index.c:82      performance: 20.644448670 s: preload_thread\n22:07:16.898969 preload-index.c:82      performance: 20.665179069 s: preload_thread\n22:07:16.903966 preload-index.c:82      performance: 20.668675830 s: preload_thread\n22:07:17.037309 preload-index.c:82      performance: 20.802909352 s: preload_thread\n22:07:17.043825 preload-index.c:82      performance: 20.808079794 s: preload_thread\n22:07:17.161141 preload-index.c:82      performance: 20.924512208 s: preload_thread\n22:07:17.164327 preload-index.c:82      performance: 20.929630917 s: preload_thread\n22:07:17.283316 preload-index.c:82      performance: 21.048249962 s: preload_thread\n22:07:17.292629 preload-index.c:82      performance: 21.058296484 s: preload_thread\n22:07:17.292911 preload-index.c:129     performance: 21.059322236 s: read_index_preload\n22:07:17.301043 read-cache.c:1226       performance: 0.008095191 s: refresh_index\n22:07:17.304204 builtin/commit.c:1385   performance: 0.003102772 s: cmd_status:update_index\n22:07:17.317878 wt-status.c:630         performance: 0.006060805 s: wt_status_collect_changes_worktree\n22:07:26.727669 wt-status.c:638         performance: 9.409656793 s: wt_status_collect_changes_index\n22:07:26.727787 wt-status.c:643         performance: 0.000000702 s: wt_status_collect_untracked\n22:07:26.727857 trace.c:414             performance: 30.895639461 s: git command: 'git' 'status' '-s' '-uno'\n\n--- F. hot cache, preloadIndex = true (patched) ---\n22:09:39.808807 builtin/commit.c:1374   performance: 0.093074742 s: cmd_status:setup\n22:09:39.893509 preload-index.c:82      performance: 0.069421408 s: preload_thread\n22:09:39.893543 preload-index.c:82      performance: 0.066854806 s: preload_thread\n22:09:39.893781 preload-index.c:82      performance: 0.083687605 s: preload_thread\n22:09:39.894532 preload-index.c:82      performance: 0.000000567 s: preload_thread\n22:09:39.894559 preload-index.c:82      performance: 0.083802495 s: preload_thread\n22:09:39.894662 preload-index.c:82      performance: 0.085355973 s: preload_thread\n22:09:39.894741 preload-index.c:82      performance: 0.031963269 s: preload_thread\n22:09:39.894919 preload-index.c:82      performance: 0.085751616 s: preload_thread\n22:09:39.895119 preload-index.c:82      performance: 0.048522415 s: preload_thread\n22:09:39.895183 preload-index.c:82      performance: 0.040487646 s: preload_thread\n22:09:39.895522 preload-index.c:82      performance: 0.000000596 s: preload_thread\n22:09:39.894037 preload-index.c:82      performance: 0.083306108 s: preload_thread\n22:09:39.894156 preload-index.c:82      performance: 0.084544605 s: preload_thread\n22:09:39.894170 preload-index.c:82      performance: 0.000000574 s: preload_thread\n22:09:39.894106 preload-index.c:82      performance: 0.084106288 s: preload_thread\n22:09:39.896097 preload-index.c:82      performance: 0.000000714 s: preload_thread\n22:09:39.896301 preload-index.c:82      performance: 0.000000579 s: preload_thread\n22:09:39.896470 preload-index.c:82      performance: 0.000000608 s: preload_thread\n22:09:39.896574 preload-index.c:82      performance: 0.000000539 s: preload_thread\n22:09:39.896753 preload-index.c:82      performance: 0.000000567 s: preload_thread\n22:09:39.897054 preload-index.c:129     performance: 0.088090726 s: read_index_preload\n22:09:39.905003 read-cache.c:1226       performance: 0.007922587 s: refresh_index\n22:09:39.908375 builtin/commit.c:1385   performance: 0.003327374 s: cmd_status:update_index\n22:09:39.913895 wt-status.c:630         performance: 0.005345165 s: wt_status_collect_changes_worktree\n22:09:40.189196 wt-status.c:638         performance: 0.275230521 s: wt_status_collect_changes_index\n22:09:40.189339 wt-status.c:643         performance: 0.000000635 s: wt_status_collect_untracked\n22:09:40.189420 trace.c:414             performance: 0.473908455 s: git command: 'git' 'status' '-s' '-uno'\n"},{"id":"244946","messageId":"53AA016B.6050900@gmail.com","threadId":"36994","inReplyTo":"53AA0129.1080109@gmail.com","subject":"[PATCH] preload-index: optimize for sequential IO","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-06-24T22:53:31Z","receivedAt":"2014-06-24T22:53:31Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Enabling core.preloadIndex on a real HD reduces cold cache performance by\n~5%. This is because the threads read from up to 20 different locations on\ndisk.\n\nAdditionally, some threads finish early (each thread is assigned a fixed\nnumber of cache entries to process in advance), i.e. preloading is not as\nparallel as we would like. With hot cache, threads finish so quickly that\nmost run in sequence rather than in parallel.\n\nChange background threads so that they run until all work is done. Use a\ncentral mutex-protected counter to iterate over available cache entries. As\ncache entries are sorted by path, this implicitly increases IO locality.\n\nThis improves cold cache performance of preload_index() by ~20% and\nhot cache performance by ~15%. Total improvement of e.g. 'git status -uno'\non WebKit is ~15% (cold cache) and ~5% (hot cache).\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n preload-index.c | 76 ++++++++++++++++++++++++++++++++++-----------------------\n 1 file changed, 45 insertions(+), 31 deletions(-)\n\ndiff --git a/preload-index.c b/preload-index.c\nindex 968ee25..6ac368d 100644\n--- a/preload-index.c\n+++ b/preload-index.c\n@@ -28,50 +28,65 @@ struct thread_data {\n \tpthread_t pthread;\n \tstruct index_state *index;\n \tstruct pathspec pathspec;\n-\tint offset, nr;\n+\tpthread_mutex_t *pmutex;\n+\tint *pnr;\n };\n \n static void *preload_thread(void *_data)\n {\n-\tint nr;\n+\tint nr, max_nr;\n \tstruct thread_data *p = _data;\n \tstruct index_state *index = p->index;\n-\tstruct cache_entry **cep = index->cache + p->offset;\n \tstruct cache_def cache;\n \n \tmemset(&cache, 0, sizeof(cache));\n-\tnr = p->nr;\n-\tif (nr + p->offset > index->cache_nr)\n-\t\tnr = index->cache_nr - p->offset;\n+\tfor (;;) {\n+\t\t/* get next batch of entries to check */\n+\t\tpthread_mutex_lock(p->pmutex);\n+\t\tnr = *p->pnr;\n+\t\t*p->pnr += THREAD_COST;\n+\t\tpthread_mutex_unlock(p->pmutex);\n \n-\tdo {\n-\t\tstruct cache_entry *ce = *cep++;\n-\t\tstruct stat st;\n+\t\tmax_nr = nr + THREAD_COST;\n+\t\tif (max_nr > index->cache_nr)\n+\t\t\tmax_nr = index->cache_nr;\n \n-\t\tif (ce_stage(ce))\n-\t\t\tcontinue;\n-\t\tif (S_ISGITLINK(ce->ce_mode))\n-\t\t\tcontinue;\n-\t\tif (ce_uptodate(ce))\n-\t\t\tcontinue;\n-\t\tif (!ce_path_match(ce, &p->pathspec, NULL))\n-\t\t\tcontinue;\n-\t\tif (threaded_has_symlink_leading_path(&cache, ce->name, ce_namelen(ce)))\n-\t\t\tcontinue;\n-\t\tif (lstat(ce->name, &st))\n-\t\t\tcontinue;\n-\t\tif (ie_match_stat(index, ce, &st, CE_MATCH_RACY_IS_DIRTY))\n-\t\t\tcontinue;\n-\t\tce_mark_uptodate(ce);\n-\t} while (--nr > 0);\n+\t\t/* break loop if no more work to do */\n+\t\tif (nr >= max_nr)\n+\t\t\tbreak;\n+\n+\t\tfor (; nr < max_nr; nr++) {\n+\t\t\tstruct cache_entry *ce = index->cache[nr];\n+\t\t\tstruct stat st;\n+\n+\t\t\tif (ce_stage(ce))\n+\t\t\t\tcontinue;\n+\t\t\tif (S_ISGITLINK(ce->ce_mode))\n+\t\t\t\tcontinue;\n+\t\t\tif (ce_uptodate(ce))\n+\t\t\t\tcontinue;\n+\t\t\tif (!ce_path_match(ce, &p->pathspec, NULL))\n+\t\t\t\tcontinue;\n+\t\t\tif (threaded_has_symlink_leading_path(&cache, ce->name,\n+\t\t\t\t\t\t\t      ce_namelen(ce)))\n+\t\t\t\tcontinue;\n+\t\t\tif (lstat(ce->name, &st))\n+\t\t\t\tcontinue;\n+\t\t\tif (ie_match_stat(index, ce, &st,\n+\t\t\t\t\t  CE_MATCH_RACY_IS_DIRTY))\n+\t\t\t\tcontinue;\n+\t\t\tce_mark_uptodate(ce);\n+\t\t}\n+\t}\n \treturn NULL;\n }\n \n static void preload_index(struct index_state *index,\n \t\t\t  const struct pathspec *pathspec)\n {\n-\tint threads, i, work, offset;\n+\tint threads, i, nr = 0;\n \tstruct thread_data data[MAX_PARALLEL];\n+\tpthread_mutex_t mutex;\n \n \tif (!core_preload_index)\n \t\treturn;\n@@ -81,17 +96,15 @@ static void preload_index(struct index_state *index,\n \t\treturn;\n \tif (threads > MAX_PARALLEL)\n \t\tthreads = MAX_PARALLEL;\n-\toffset = 0;\n-\twork = DIV_ROUND_UP(index->cache_nr, threads);\n \tmemset(&data, 0, sizeof(data));\n+\tpthread_mutex_init(&mutex, NULL);\n \tfor (i = 0; i < threads; i++) {\n \t\tstruct thread_data *p = data+i;\n \t\tp->index = index;\n \t\tif (pathspec)\n \t\t\tcopy_pathspec(&p->pathspec, pathspec);\n-\t\tp->offset = offset;\n-\t\tp->nr = work;\n-\t\toffset += work;\n+\t\tp->pnr = &nr;\n+\t\tp->pmutex = &mutex;\n \t\tif (pthread_create(&p->pthread, NULL, preload_thread, p))\n \t\t\tdie(\"unable to create threaded lstat\");\n \t}\n@@ -100,6 +113,7 @@ static void preload_index(struct index_state *index,\n \t\tif (pthread_join(p->pthread, NULL))\n \t\t\tdie(\"unable to join threaded lstat\");\n \t}\n+\tpthread_mutex_destroy(&mutex);\n }\n #endif\n \n-- \n1.9.4.msysgit.0.1.gc8a51b4\n"},{"id":"244947","messageId":"53AA01AE.8010707@gmail.com","threadId":"36994","inReplyTo":"53AA0129.1080109@gmail.com","subject":"[PATCH (experimental)] preload-index: make parallel IO configurable","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-06-24T22:54:38Z","receivedAt":"2014-06-24T22:54:38Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Make the amount of IO parallelism configurable (i.e. number of separate\nindex sections to be processed in parallel).\n\nDefining PARALLEL_IO = 20 restores approximately the IO pattern of the\noriginal preload_index() implementation. Best performance is achieved with\nPARALLEL_IO = 1 (i.e. sequential IO).\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n\nApplies on top of \"preload-index: optimize for sequential IO\".\n\n preload-index.c | 22 +++++++++++++++++-----\n 1 file changed, 17 insertions(+), 5 deletions(-)\n\ndiff --git a/preload-index.c b/preload-index.c\nindex 6ac368d..5fe5521 100644\n--- a/preload-index.c\n+++ b/preload-index.c\n@@ -23,6 +23,7 @@ static void preload_index(struct index_state *index,\n  */\n #define MAX_PARALLEL (20)\n #define THREAD_COST (500)\n+#define PARALLEL_IO (1)\n \n struct thread_data {\n \tpthread_t pthread;\n@@ -38,23 +39,34 @@ static void *preload_thread(void *_data)\n \tstruct thread_data *p = _data;\n \tstruct index_state *index = p->index;\n \tstruct cache_def cache;\n+\tint blocks = DIV_ROUND_UP(index->cache_nr, THREAD_COST);\n+\tint step = DIV_ROUND_UP(blocks, PARALLEL_IO);\n \n \tmemset(&cache, 0, sizeof(cache));\n \tfor (;;) {\n \t\t/* get next batch of entries to check */\n \t\tpthread_mutex_lock(p->pmutex);\n \t\tnr = *p->pnr;\n-\t\t*p->pnr += THREAD_COST;\n+\t\t(*p->pnr)++;\n \t\tpthread_mutex_unlock(p->pmutex);\n \n+\t\t/* break loop if no more work to do */\n+\t\tif (nr >= blocks + PARALLEL_IO - 1)\n+\t\t\tbreak;\n+\n+\t\t/*\n+\t\t * rearrange iteration order, i.e. with PARALLEL_IO = 2,\n+\t\t * [0, 1, 2, 3, 4, 5, 6, 7] becomes [0, 4, 1, 5, 2, 6, 3, 7]\n+\t\t */\n+\t\tnr = (nr / PARALLEL_IO) + (nr % PARALLEL_IO) * step;\n+\t\tif (nr >= blocks)\n+\t\t\tcontinue;\n+\t\tnr *= THREAD_COST;\n+\n \t\tmax_nr = nr + THREAD_COST;\n \t\tif (max_nr > index->cache_nr)\n \t\t\tmax_nr = index->cache_nr;\n \n-\t\t/* break loop if no more work to do */\n-\t\tif (nr >= max_nr)\n-\t\t\tbreak;\n-\n \t\tfor (; nr < max_nr; nr++) {\n \t\t\tstruct cache_entry *ce = index->cache[nr];\n \t\t\tstruct stat st;\n-- \n1.9.4.msysgit.0.1.gc8a51b4\n"},{"id":"244948","messageId":"53AA0228.4080600@gmail.com","threadId":"36994","inReplyTo":"53AA0129.1080109@gmail.com","subject":"[PATCH (performance tracing)] test git-status performance","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-06-24T22:56:40Z","receivedAt":"2014-06-24T22:56:40Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Add trace_performance output to functions involved in git-status.\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n\nApplies on top of performance-tracing topic.\n\n builtin/commit.c |  8 ++++++++\n preload-index.c  |  4 ++++\n read-cache.c     |  2 ++\n wt-status.c      | 11 +++++++++++\n 4 files changed, 25 insertions(+)\n\ndiff --git a/builtin/commit.c b/builtin/commit.c\nindex 94eb8a3..6a38fa2 100644\n--- a/builtin/commit.c\n+++ b/builtin/commit.c\n@@ -1322,9 +1322,11 @@ static int git_status_config(const char *k, const char *v, void *cb)\n \n int cmd_status(int argc, const char **argv, const char *prefix)\n {\n+\tuint64_t start = getnanotime();\n \tstatic struct wt_status s;\n \tint fd;\n \tunsigned char sha1[20];\n+\n \tstatic struct option builtin_status_options[] = {\n \t\tOPT__VERBOSE(&verbose, N_(\"be verbose\")),\n \t\tOPT_SET_INT('s', \"short\", &status_format,\n@@ -1369,13 +1371,19 @@ int cmd_status(int argc, const char **argv, const char *prefix)\n \t\t       PATHSPEC_PREFER_FULL,\n \t\t       prefix, argv);\n \n+\ttrace_performance_since(start, \"cmd_status:setup\");\n+\n \tread_cache_preload(&s.pathspec);\n \trefresh_index(&the_index, REFRESH_QUIET|REFRESH_UNMERGED, &s.pathspec, NULL, NULL);\n \n+\tstart = getnanotime();\n+\n \tfd = hold_locked_index(&index_lock, 0);\n \tif (0 <= fd)\n \t\tupdate_index_if_able(&the_index, &index_lock);\n \n+\ttrace_performance_since(start, \"cmd_status:update_index\");\n+\n \ts.is_initial = get_sha1(s.reference, sha1) ? 1 : 0;\n \ts.ignore_submodule_arg = ignore_submodule_arg;\n \twt_status_collect(&s);\ndiff --git a/preload-index.c b/preload-index.c\nindex 968ee25..189c5a4 100644\n--- a/preload-index.c\n+++ b/preload-index.c\n@@ -33,6 +33,7 @@ struct thread_data {\n \n static void *preload_thread(void *_data)\n {\n+\tuint64_t start = getnanotime();\n \tint nr;\n \tstruct thread_data *p = _data;\n \tstruct index_state *index = p->index;\n@@ -64,6 +65,7 @@ static void *preload_thread(void *_data)\n \t\t\tcontinue;\n \t\tce_mark_uptodate(ce);\n \t} while (--nr > 0);\n+\ttrace_performance_since(start, \"preload_thread\");\n \treturn NULL;\n }\n \n@@ -106,8 +108,10 @@ static void preload_index(struct index_state *index,\n int read_index_preload(struct index_state *index,\n \t\t       const struct pathspec *pathspec)\n {\n+\tuint64_t start = getnanotime();\n \tint retval = read_index(index);\n \n \tpreload_index(index, pathspec);\n+\ttrace_performance_since(start, \"read_index_preload\");\n \treturn retval;\n }\ndiff --git a/read-cache.c b/read-cache.c\nindex 132d032..5c6b763 100644\n--- a/read-cache.c\n+++ b/read-cache.c\n@@ -1136,6 +1136,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,\n \t\t  const struct pathspec *pathspec,\n \t\t  char *seen, const char *header_msg)\n {\n+\tuint64_t start = getnanotime();\n \tint i;\n \tint has_errors = 0;\n \tint really = (flags & REFRESH_REALLY) != 0;\n@@ -1222,6 +1223,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,\n \n \t\treplace_index_entry(istate, i, new);\n \t}\n+\ttrace_performance_since(start, \"refresh_index\");\n \treturn has_errors;\n }\n \ndiff --git a/wt-status.c b/wt-status.c\nindex 318a191..a744565 100644\n--- a/wt-status.c\n+++ b/wt-status.c\n@@ -623,13 +623,24 @@ static void wt_status_collect_untracked(struct wt_status *s)\n \n void wt_status_collect(struct wt_status *s)\n {\n+\tuint64_t start = getnanotime();\n+\n \twt_status_collect_changes_worktree(s);\n \n+\ttrace_performance_since(start, \"wt_status_collect_changes_worktree\");\n+\tstart = getnanotime();\n+\n \tif (s->is_initial)\n \t\twt_status_collect_changes_initial(s);\n \telse\n \t\twt_status_collect_changes_index(s);\n+\n+\ttrace_performance_since(start, \"wt_status_collect_changes_index\");\n+\tstart = getnanotime();\n+\n \twt_status_collect_untracked(s);\n+\n+\ttrace_performance_since(start, \"wt_status_collect_untracked\");\n }\n \n static void wt_status_print_unmerged(struct wt_status *s)\n-- \n1.9.4.msysgit.0.1.gc8a51b4\n"},{"id":"244949","messageId":"1403651538.22828.4.camel@stross","threadId":"36994","inReplyTo":"53AA0129.1080109@gmail.com","subject":"Re: Git-status / preload_index() performance","fromName":"David Turner","fromEmail":"dturner@twopensource.com","sentAt":"2014-06-24T23:12:18Z","receivedAt":"2014-06-24T23:12:18Z","isPatch":false,"sender":{"key":"novalis@novalis.org","avatar":"https://avatars.githubusercontent.com/u/77003?v=4"},"body":"On Wed, 2014-06-25 at 00:52 +0200, Karsten Blees wrote:\n> Even more time is spent unpacking the HEAD tree, even with hot cache (repacking with depth 10 reduces this to ~250ms, on SSD its just 7ms). Perhaps caching the HEAD tree in an index extension could help here?\n\nThis is approximately what the cache-tree extension does.  However, it's\na bit broken.  I've been working on a fix, but slowly because my other\nwork has taken me longer than expected.  You can see the effect of the\ncache-tree extension by doing git reset --hard HEAD; this temporarily\nrestores that extension.\n"},{"id":"244950","messageId":"53AA08D1.5080205@gmail.com","threadId":"36994","inReplyTo":"1403651538.22828.4.camel@stross","subject":"Re: Git-status / preload_index() performance","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-06-24T23:25:05Z","receivedAt":"2014-06-24T23:25:05Z","isPatch":false,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 25.06.2014 01:12, schrieb David Turner:\n> On Wed, 2014-06-25 at 00:52 +0200, Karsten Blees wrote:\n>> Even more time is spent unpacking the HEAD tree, even with hot cache (repacking with depth 10 reduces this to ~250ms, on SSD its just 7ms). Perhaps caching the HEAD tree in an index extension could help here?\n> \n> This is approximately what the cache-tree extension does.  However, it's\n> a bit broken.  I've been working on a fix, but slowly because my other\n> work has taken me longer than expected.  You can see the effect of the\n> cache-tree extension by doing git reset --hard HEAD; this temporarily\n> restores that extension.\n> \n\nIndeed:\n\n01:32:35.965910 builtin/commit.c:1374   performance: 0.097505786 s: cmd_status:setup\n...\n01:32:36.047534 preload-index.c:129     performance: 0.081458337 s: read_index_preload\n01:32:36.056204 read-cache.c:1226       performance: 0.008641527 s: refresh_index\n01:32:36.059237 builtin/commit.c:1385   performance: 0.002997060 s: cmd_status:update_index\n01:32:36.065163 wt-status.c:630         performance: 0.005732979 s: wt_status_collect_changes_worktree\n01:32:36.072078 wt-status.c:638         performance: 0.006832976 s: wt_status_collect_changes_index\n01:32:36.072150 wt-status.c:643         performance: 0.000000374 s: wt_status_collect_untracked\n01:32:36.072211 trace.c:414             performance: 0.204069579 s: git command: 'git' 'status' '-s' '-uno'\n\nThanks\n"},{"id":"245016","messageId":"CACsJy8Bkfz6=WUy0RsXd0e9dXqocUFXhAaO0dpUg+AjZ5RNeNA@mail.gmail.com","threadId":"36994","inReplyTo":"53AA0228.4080600@gmail.com","subject":"Re: [PATCH (performance tracing)] test git-status performance","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2014-06-26T12:30:55Z","receivedAt":"2014-06-26T12:30:55Z","isPatch":true,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Wed, Jun 25, 2014 at 5:56 AM, Karsten Blees <karsten.blees@gmail.com> wrote:\n>  void wt_status_collect(struct wt_status *s)\n>  {\n> +       uint64_t start = getnanotime();\n> +\n>         wt_status_collect_changes_worktree(s);\n>\n> +       trace_performance_since(start, \"wt_status_collect_changes_worktree\");\n> +       start = getnanotime();\n> +\n>         if (s->is_initial)\n>                 wt_status_collect_changes_initial(s);\n>         else\n>                 wt_status_collect_changes_index(s);\n> +\n> +       trace_performance_since(start, \"wt_status_collect_changes_index\");\n> +       start = getnanotime();\n> +\n>         wt_status_collect_untracked(s);\n> +\n> +       trace_performance_since(start, \"wt_status_collect_untracked\");\n>  }\n\nNow that we have good perf measuring support, perhaps the next step is\nremove gettimeofday() in advice_status_u_option related code in\nwt_status_collect_untracked().\n-- \nDuy\n"},{"id":"246755","messageId":"CACsJy8BugcnUF1AmLqZ3jnWiRtark81jOTGkDP-xCr8LBgaf8A@mail.gmail.com","threadId":"36994","inReplyTo":"53AA0228.4080600@gmail.com","subject":"Re: [PATCH (performance tracing)] test git-status performance","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2014-07-26T09:59:08Z","receivedAt":"2014-07-26T09:59:08Z","isPatch":true,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Wed, Jun 25, 2014 at 5:56 AM, Karsten Blees <karsten.blees@gmail.com> wrote:\n> Add trace_performance output to functions involved in git-status.\n>\n> Signed-off-by: Karsten Blees <blees@dcon.de>\n\nShould this patch be merged to git.git? It's useful for tracking\nperformance (of git-status) and does not seem to have any negative\nimpacts.\n\n> ---\n>\n> Applies on top of performance-tracing topic.\n>\n>  builtin/commit.c |  8 ++++++++\n>  preload-index.c  |  4 ++++\n>  read-cache.c     |  2 ++\n>  wt-status.c      | 11 +++++++++++\n>  4 files changed, 25 insertions(+)\n>\n> diff --git a/builtin/commit.c b/builtin/commit.c\n> index 94eb8a3..6a38fa2 100644\n> --- a/builtin/commit.c\n> +++ b/builtin/commit.c\n> @@ -1322,9 +1322,11 @@ static int git_status_config(const char *k, const char *v, void *cb)\n>\n>  int cmd_status(int argc, const char **argv, const char *prefix)\n>  {\n> +       uint64_t start = getnanotime();\n>         static struct wt_status s;\n>         int fd;\n>         unsigned char sha1[20];\n> +\n>         static struct option builtin_status_options[] = {\n>                 OPT__VERBOSE(&verbose, N_(\"be verbose\")),\n>                 OPT_SET_INT('s', \"short\", &status_format,\n> @@ -1369,13 +1371,19 @@ int cmd_status(int argc, const char **argv, const char *prefix)\n>                        PATHSPEC_PREFER_FULL,\n>                        prefix, argv);\n>\n> +       trace_performance_since(start, \"cmd_status:setup\");\n> +\n>         read_cache_preload(&s.pathspec);\n>         refresh_index(&the_index, REFRESH_QUIET|REFRESH_UNMERGED, &s.pathspec, NULL, NULL);\n>\n> +       start = getnanotime();\n> +\n>         fd = hold_locked_index(&index_lock, 0);\n>         if (0 <= fd)\n>                 update_index_if_able(&the_index, &index_lock);\n>\n> +       trace_performance_since(start, \"cmd_status:update_index\");\n> +\n>         s.is_initial = get_sha1(s.reference, sha1) ? 1 : 0;\n>         s.ignore_submodule_arg = ignore_submodule_arg;\n>         wt_status_collect(&s);\n> diff --git a/preload-index.c b/preload-index.c\n> index 968ee25..189c5a4 100644\n> --- a/preload-index.c\n> +++ b/preload-index.c\n> @@ -33,6 +33,7 @@ struct thread_data {\n>\n>  static void *preload_thread(void *_data)\n>  {\n> +       uint64_t start = getnanotime();\n>         int nr;\n>         struct thread_data *p = _data;\n>         struct index_state *index = p->index;\n> @@ -64,6 +65,7 @@ static void *preload_thread(void *_data)\n>                         continue;\n>                 ce_mark_uptodate(ce);\n>         } while (--nr > 0);\n> +       trace_performance_since(start, \"preload_thread\");\n>         return NULL;\n>  }\n>\n> @@ -106,8 +108,10 @@ static void preload_index(struct index_state *index,\n>  int read_index_preload(struct index_state *index,\n>                        const struct pathspec *pathspec)\n>  {\n> +       uint64_t start = getnanotime();\n>         int retval = read_index(index);\n>\n>         preload_index(index, pathspec);\n> +       trace_performance_since(start, \"read_index_preload\");\n>         return retval;\n>  }\n> diff --git a/read-cache.c b/read-cache.c\n> index 132d032..5c6b763 100644\n> --- a/read-cache.c\n> +++ b/read-cache.c\n> @@ -1136,6 +1136,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,\n>                   const struct pathspec *pathspec,\n>                   char *seen, const char *header_msg)\n>  {\n> +       uint64_t start = getnanotime();\n>         int i;\n>         int has_errors = 0;\n>         int really = (flags & REFRESH_REALLY) != 0;\n> @@ -1222,6 +1223,7 @@ int refresh_index(struct index_state *istate, unsigned int flags,\n>\n>                 replace_index_entry(istate, i, new);\n>         }\n> +       trace_performance_since(start, \"refresh_index\");\n>         return has_errors;\n>  }\n>\n> diff --git a/wt-status.c b/wt-status.c\n> index 318a191..a744565 100644\n> --- a/wt-status.c\n> +++ b/wt-status.c\n> @@ -623,13 +623,24 @@ static void wt_status_collect_untracked(struct wt_status *s)\n>\n>  void wt_status_collect(struct wt_status *s)\n>  {\n> +       uint64_t start = getnanotime();\n> +\n>         wt_status_collect_changes_worktree(s);\n>\n> +       trace_performance_since(start, \"wt_status_collect_changes_worktree\");\n> +       start = getnanotime();\n> +\n>         if (s->is_initial)\n>                 wt_status_collect_changes_initial(s);\n>         else\n>                 wt_status_collect_changes_index(s);\n> +\n> +       trace_performance_since(start, \"wt_status_collect_changes_index\");\n> +       start = getnanotime();\n> +\n>         wt_status_collect_untracked(s);\n> +\n> +       trace_performance_since(start, \"wt_status_collect_untracked\");\n>  }\n>\n>  static void wt_status_print_unmerged(struct wt_status *s)\n-- \nDuy\n"},{"id":"246756","messageId":"CACsJy8DxyS9_L8_yFo-mXe3=SNFALV6Qx2tCaZe=q2uMKLWNdQ@mail.gmail.com","threadId":"36994","inReplyTo":"CACsJy8BugcnUF1AmLqZ3jnWiRtark81jOTGkDP-xCr8LBgaf8A@mail.gmail.com","subject":"Re: [PATCH (performance tracing)] test git-status performance","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2014-07-26T10:33:27Z","receivedAt":"2014-07-26T10:33:27Z","isPatch":true,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Sat, Jul 26, 2014 at 4:59 PM, Duy Nguyen <pclouds@gmail.com> wrote:\n> On Wed, Jun 25, 2014 at 5:56 AM, Karsten Blees <karsten.blees@gmail.com> wrote:\n>> Add trace_performance output to functions involved in git-status.\n>>\n>> Signed-off-by: Karsten Blees <blees@dcon.de>\n>\n> Should this patch be merged to git.git? It's useful for tracking\n> performance (of git-status) and does not seem to have any negative\n> impacts.\n\nHm... I don't like the changes in commit.c and rather print running\ntime inside read_index_from() and update_index_if_able(). So people\nmay prefer different ways of measuring and these patches should\nprobably stay private. Although if we have something like this shipped\nin every distro, asking the user to run with $GIT_TRACE_PERFORMANCE\ncould help..\n-- \nDuy\n"}]}