| Message ID | 2016ef2e342c2ec6517afa8ec3e57035021fb965.1650547400.git.dyroneteng@gmail.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | trace2 output for bitmap decision path | expand |
On Thu, Apr 21 2022, Teng Long wrote: Thanks for following up.. > 19:38:43.007840 common-main.c:49 | d0 | main | version | | | | | 2.35.1.582.g8e9092487a > 19:38:43.007874 common-main.c:50 | d0 | main | start | | 0.000305 | | | /opt/git/master/bin/git rev-list --test-bitmap HEAD It's really helpful to have these full examples in the commit message. Thanks. > --- a/pack-bitmap.c > +++ b/pack-bitmap.c > @@ -312,9 +312,12 @@ char *pack_bitmap_filename(struct packed_git *p) > static int open_midx_bitmap_1(struct bitmap_index *bitmap_git, > struct multi_pack_index *midx) > { > + int fd; > struct stat st; > char *bitmap_name = midx_bitmap_filename(midx); > - int fd = git_open(bitmap_name); > + trace2_data_string("midx", the_repository, "try to open bitmap", > + bitmap_name); > + fd = git_open(bitmap_name); > > free(bitmap_name); Hrm, so re my comment on 5/5 are you trying to use the "try to open" as a timer to see what our start time is? I think probably not, in which case this whole variable flip-around is something we won't need. But if we do actually need it perhaps a sub-region for the timing? > @@ -511,11 +530,18 @@ static int open_midx_bitmap(struct repository *r, > static int open_bitmap(struct repository *r, > struct bitmap_index *bitmap_git) > { > - assert(!bitmap_git->map); > + int ret = -1; > > - if (!open_midx_bitmap(r, bitmap_git)) > - return 0; > - return open_pack_bitmap(r, bitmap_git); > + assert(!bitmap_git->map); > + trace2_region_enter("pack-bitmap", "open_bitmap", r); > + if (!open_midx_bitmap(r, bitmap_git)) { > + ret = 0; Nit: I think these "goto" patterns are best if your "int ret = N" picks an "N" which is the default that you'll "goto", i.e. if you pick "ret = 0" you'll just need "goto done" here.... > + goto done; > + } > + ret = open_pack_bitmap(r, bitmap_git); ...which we may then override here. Just saves you the assignment and the {}, but it tends to add up in longer functions. > +done: > + trace2_region_leave("pack-bitmap", "open_bitmap", r); > + return ret; > } Looks good, aside from the 5/5 comments that much of the data string logging looks like it becomes redundant in the end due to error() giving us the same thing. > struct bitmap_index *prepare_bitmap_git(struct repository *r) > diff --git a/repo-settings.c b/repo-settings.c > index b4fbd16cdc..5bc7a97a6d 100644 > --- a/repo-settings.c > +++ b/repo-settings.c > @@ -8,6 +8,7 @@ static void repo_cfg_bool(struct repository *r, const char *key, int *dest, > { > if (repo_config_get_bool(r, key, dest)) > *dest = def; > + trace2_data_string("config", r, key, *dest ? "true" : "false"); > } > > void prepare_repo_settings(struct repository *r) > diff --git a/t/t5310-pack-bitmaps.sh b/t/t5310-pack-bitmaps.sh > index eb63b71852..664cb88b0b 100755 > --- a/t/t5310-pack-bitmaps.sh > +++ b/t/t5310-pack-bitmaps.sh > @@ -421,8 +421,8 @@ test_expect_success 'complains about multiple pack bitmaps' ' > test_line_count = 2 bitmaps && > > git rev-list --use-bitmap-index HEAD 2>err && > - grep "a bitmap has been opened" err && > - grep "ignoring extra bitmap file" err > + grep "warning: a normal or midx bitmap already has been opened" err && > + grep "warning: ignoring extra bitmap file" err > ) > ' I haven't tested but part of this test change looks like it'll break under bisect, i.e. you changed 1/2 of these strings in 3/5. Did you try with "git rebase -i -x 'make test T=t*bitmap*" or similar?
On 4/21/22 9:26 AM, Teng Long wrote: > It's supported for a Git repo to use bitmap in both normal bitmap way > or a multi-pack-index bitmap. > > Sometimes the debug path is not obvious, for example, when executing: > > $git rev-list --test-bitmap HEAD > fatal: failed to load bitmap indexes > > If we see the output like this, we are not sure about what's happened, > because the cause should be : > > 1. neither normal nor midx bitmap exists > 2. only midx bitmap exists but core.multipackIndex="false" > 3. core.multipackIndex="true" but midx bitmap file is currupt > 4. core.multipackIndex="true" and no midx bitmap exists but > normal bitmap file is currupt > .... > > These are some of the scenarios I briefly tested, but maybe there are > others (some scenarios is produced manually like "currupt bitmap file", > but it's not represent it's an existed bug.). > > Therefore, we added some TRACE2 code so that when we read the bitmap > we can be more clear about the decision path, such as whether it is > working on midx bitmap or normal bitmap, or is it simply because the > related configuration is disabled. This may help with logging, user > troubleshooting, and development debugging. > > Here are some output examples when executing > "$GIT_TRACE2_PERF=1 git rev-list --test-bitmap HEAD" under different > situations: > > 1. _HAVE_ MIDX bitmap and NORMAL bitmap file, but the > "core.multipackIndex" configures as "false": > > 19:38:43.007840 common-main.c:49 | d0 | main | version | | | | | 2.35.1.582.g8e9092487a > 19:38:43.007874 common-main.c:50 | d0 | main | start | | 0.000305 | | | /opt/git/master/bin/git rev-list --test-bitmap HEAD > 19:38:43.007950 compat/linux/procinfo.c:170 | d0 | main | cmd_ancestry | | | | | ancestry:[bash sshd sshd sshd systemd] > 19:38:43.008091 git.c:460 | d0 | main | cmd_name | | | | | rev-list (rev-list) > 19:38:43.008284 repo-settings.c:11 | d0 | main | data | r0 | 0.000720 | 0.000720 | config | feature.manyfiles:false > 19:38:43.008297 repo-settings.c:11 | d0 | main | data | r0 | 0.000734 | 0.000734 | config | feature.experimental:false > 19:38:43.008305 repo-settings.c:11 | d0 | main | data | r0 | 0.000742 | 0.000742 | config | core.commitgraph:true > 19:38:43.008313 repo-settings.c:11 | d0 | main | data | r0 | 0.000749 | 0.000749 | config | commitgraph.readchangedpaths:true > 19:38:43.008320 repo-settings.c:11 | d0 | main | data | r0 | 0.000756 | 0.000756 | config | gc.writecommitgraph:true > 19:38:43.008327 repo-settings.c:11 | d0 | main | data | r0 | 0.000764 | 0.000764 | config | fetch.writecommitgraph:false > 19:38:43.008334 repo-settings.c:11 | d0 | main | data | r0 | 0.000770 | 0.000770 | config | pack.usesparse:true > 19:38:43.008341 repo-settings.c:11 | d0 | main | data | r0 | 0.000777 | 0.000777 | config | core.multipackindex:false > 19:38:43.008348 repo-settings.c:11 | d0 | main | data | r0 | 0.000784 | 0.000784 | config | index.sparse:false > 19:38:43.008724 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001160 | | pack-bitmap | label:open_bitmap > 19:38:43.008738 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001173 | 0.000013 | bitmap | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap > 19:38:43.008754 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001191 | 0.000031 | pack-bitmap | label:open_bitmap > Bitmap v1 test (8 entries loaded) > Found bitmap for 0a7df7ae92f8d8ed879c240f8ae9cdd33d18085e. 64 bits / 1801edc6 checksum > 19:38:43.009099 progress.c:268 | d0 | main | region_enter | r0 | 0.001535 | | progress | label:Verifying bitmap entries > Verifying bitmap entries: 100% (27/27), done. > 19:38:43.009294 progress.c:339 | d0 | main | data | r0 | 0.001730 | 0.000195 | progress | ..total_objects:27 > 19:38:43.009302 progress.c:346 | d0 | main | region_leave | r0 | 0.001739 | 0.000204 | progress | label:Verifying bitmap entries > OK! > 19:38:43.009321 git.c:718 | d0 | main | exit | | 0.001757 | | | code:0 > 19:38:43.009329 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001766 | | | code:0 > > 2. _HAVE_ MIDX bitmap and NORMAL bitmap file, but the > "core.multipackIndex" configures as "true": > > (omit duplicate outputs) > ... > 20:02:31.288797 repo-settings.c:11 | d0 | main | data | r0 | 0.000811 | 0.000811 | config | core.multipackindex:true > 20:02:31.288806 repo-settings.c:11 | d0 | main | data | r0 | 0.000819 | 0.000819 | config | index.sparse:false > 20:02:31.288836 midx.c:185 | d0 | main | data | r0 | 0.000849 | 0.000849 | midx | load/num_packs:1 > 20:02:31.288843 midx.c:186 | d0 | main | data | r0 | 0.000857 | 0.000857 | midx | load/num_objects:27 > 20:02:31.289217 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001229 | | pack-bitmap | label:open_bitmap > 20:02:31.289230 pack-bitmap.c:318 | d0 | main | data | r0 | 0.001242 | 0.000013 | midx | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/multi-pack-index-b6b04fbe053bd500d9ca13354466d3249dc275ac.bitmap > 20:02:31.289252 pack-revindex.c:315 | d0 | main | data | r0 | 0.001265 | 0.000036 | load_midx_re | ..source:midx > 20:02:31.289261 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001274 | 0.000045 | pack-bitmap | label:open_bitmap > Bitmap v1 test (8 entries loaded) > Found bitmap for 0a7df7ae92f8d8ed879c240f8ae9cdd33d18085e. 64 bits / 1801edc6 checksum > 20:02:31.289594 progress.c:268 | d0 | main | region_enter | r0 | 0.001607 | | progress | label:Verifying bitmap entries > Verifying bitmap entries: 100% (27/27), done. > 20:02:31.289810 progress.c:339 | d0 | main | data | r0 | 0.001823 | 0.000216 | progress | ..total_objects:27 > 20:02:31.289824 progress.c:346 | d0 | main | region_leave | r0 | 0.001837 | 0.000230 | progress | label:Verifying bitmap entries > OK! > 20:02:31.289843 git.c:718 | d0 | main | exit | | 0.001856 | | | code:0 > 20:02:31.289860 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001873 | | | code:0 > > 3. _HAVE_ MIDX bitmap and a corrupt NORMAL bitmap file, but the > "core.multipackIndex" configures as "false" : > > (omit duplicate outputs) > ... > 20:14:06.539305 repo-settings.c:11 | d0 | main | data | r0 | 0.000794 | 0.000794 | config | core.multipackindex:false > 20:14:06.539310 repo-settings.c:11 | d0 | main | data | r0 | 0.000799 | 0.000799 | config | index.sparse:false > 20:14:06.539658 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001146 | | pack-bitmap | label:open_bitmap > 20:14:06.539671 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001160 | 0.000014 | bitmap | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap > 20:14:06.539686 usage.c:79 | d0 | main | error | | | | | ..Corrupted bitmap index file (wrong header) > error: Corrupted bitmap index file (wrong header) > 20:14:06.539696 pack-bitmap.c:426 | d0 | main | data | r0 | 0.001185 | 0.000039 | bitmap | ..load bitmap header:failed > 20:14:06.539709 usage.c:79 | d0 | main | error | | | | | ..bitmap header is invalid > error: bitmap header is invalid > 20:14:06.539719 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001208 | 0.000062 | pack-bitmap | label:open_bitmap > 20:14:06.539726 usage.c:60 | d0 | main | error | | | | | failed to load bitmap indexes > fatal: failed to load bitmap indexes > 20:14:06.539735 usage.c:74 | d0 | main | exit | | 0.001224 | | | code:128 > 20:14:06.539744 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001233 | | | code:128 > > Signed-off-by: Teng Long <dyroneteng@gmail.com> > --- > pack-bitmap.c | 40 +++++++++++++++++++++++++++++++++------- > repo-settings.c | 1 + > t/t5310-pack-bitmaps.sh | 4 ++-- > 3 files changed, 36 insertions(+), 9 deletions(-) > > diff --git a/pack-bitmap.c b/pack-bitmap.c > index 1b268f655e..a1d06c4252 100644 > --- a/pack-bitmap.c > +++ b/pack-bitmap.c > @@ -312,9 +312,12 @@ char *pack_bitmap_filename(struct packed_git *p) > static int open_midx_bitmap_1(struct bitmap_index *bitmap_git, > struct multi_pack_index *midx) > { > + int fd; > struct stat st; > char *bitmap_name = midx_bitmap_filename(midx); > - int fd = git_open(bitmap_name); > + trace2_data_string("midx", the_repository, "try to open bitmap", > + bitmap_name); > + fd = git_open(bitmap_name); This might just be a style thing, but rather than logging the pathname in a separate data_string message, you can use the _printf version of region_enter and region_leave to also print the name of the path -- like I did in read-cache.c for the "do_read_index" calls. ... | region_enter | ... | index | label:do_read_index .git/index ... ... | region_leave | ... | index | label:do_read_index .git/index As AEvar suggests in another message in this thread, I'm not sure if you need the region timing here for reading the bitmap, but all of the error and any other data messages will be bounded between the region_enter and region_leave events and that might (or might not) be helpful. Also, I agree with AEvar's statements about using error() and getting the trace2 error messages for free and not needing some of the trace2_data_string() messages that you have later in this file. I wonder if it would be worth adding the pathname of the invalid file to those new error messages. Granted you'll have it in the trace2 log, but then you'll also get it on stderr if that would be helpful. Jeff
On Thu, 21 Apr 2022 17:51:30 +0200, Ævar Arnfjörð Bjarmason wrote: > It's really helpful to have these full examples in the commit > message. Thanks. From the previous contribution process, I think it is necessary to provide sufficient information in patch, which can help to save reviewer's time and find problems faster. > Hrm, so re my comment on 5/5 are you trying to use the "try to open" as > a timer to see what our start time is? > > I think probably not, in which case this whole variable flip-around is > something we won't need. > > But if we do actually need it perhaps a sub-region for the timing? Yes, I looked back on it and found it's redundant and unnecessary now. Will delete the two related references in the code in next patch. > Nit: I think these "goto" patterns are best if your "int ret = N" picks > an "N" which is the default that you'll "goto", i.e. if you pick "ret = > 0" you'll just need "goto done" here.... > > > + goto done; > > + } > > + ret = open_pack_bitmap(r, bitmap_git); > > ...which we may then override here. > > Just saves you the assignment and the {}, but it tends to add up in > longer functions Make sense. > > +done: > > + trace2_region_leave("pack-bitmap", "open_bitmap", r); > > + return ret; > > } > > Looks good, aside from the 5/5 comments that much of the data string > logging looks like it becomes redundant in the end due to error() giving > us the same thing. Oops, I will read the comments and reply them in 5/5. > I haven't tested but part of this test change looks like it'll break > under bisect, i.e. you changed 1/2 of these strings in 3/5. Did you try > with "git rebase -i -x 'make test T=t*bitmap*" or similar? Yes, they should be in the same commit in 3/5, but now I the new warning text seems like is much verbose which suggested by Taylor Blau, and I will roll back the new warning message and fix the broken test under bisect. Thanks.
> Hrm, so re my comment on 5/5 are you trying to use the "try to open" as > a timer to see what our start time is? > > I think probably not, in which case this whole variable flip-around is > something we won't need. > > But if we do actually need it perhaps a sub-region for the timing? By the way, I think it will be better replace "try to open" with the bitmap name so we can also know about what kind of bitmap we are opening by filename. Before: 19:38:43.008724 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001160 | | pack-bitmap | label:open_bitmap 19:38:43.008738 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001173 | 0.000013 | bitmap | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap 19:38:43.008754 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001191 | 0.000031 | pack-bitmap | label:open_bitmap After: 19:38:43.008724 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001160 | | pack-bitmap | label:open_bitmap 19:38:43.008738 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001173 | 0.000013 | bitmap | ../home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap 19:38:43.008754 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001191 | 0.000031 | pack-bitmap | label:open_bitmap Thanks.
> This might just be a style thing, but rather than logging the pathname > in a separate data_string message, you can use the _printf version of > region_enter and region_leave to also print the name of the > path -- like I did in read-cache.c for the "do_read_index" > calls. > > ... | region_enter | ... | index | label:do_read_index .git/index > ... > ... | region_leave | ... | index | label:do_read_index .git/index Appreciate for the input about the _printf version, we can choose to let the region_enter and region_leave to print the pathname by moving the related "midx_bitmap_filename()" and "pack_bitmap_filename" at front, but it's not enough because both midx and normal bitmap support multiple opening, so it's likely we keep on the current way using "trace2_data_string()" in "open_pack_bitmap_1()" and "open_midx_bitmap_1()" is a simpler solution. I'm not sure If I totally get the meaning about your suggestion, so correct me if I understand you wrong. > As AEvar suggests in another message in this thread, I'm not sure if > you need the region timing here for reading the bitmap, but all of > the error and any other data messages will be bounded between the > region_enter and region_leave events and that might (or might not) > be helpful. I think it's needed in my opinion, the bounded between the region is helpful, especially when we want to know the detailed debug info like we do in "open_midx_bitmap_1()". > Also, I agree with AEvar's statements about using error() and getting > the trace2 error messages for free and not needing some of the > trace2_data_string() messages that you have later in this file. > > I wonder if it would be worth adding the pathname of the invalid > file to those new error messages. Granted you'll have it in the > trace2 log, but then you'll also get it on stderr if that would > be helpful. I think I will remove the redundant "trace2_data_string()" code when it will return by "error()". Thanks.
On 5/6/22 8:43 AM, Teng Long wrote: >> This might just be a style thing, but rather than logging the pathname >> in a separate data_string message, you can use the _printf version of >> region_enter and region_leave to also print the name of the >> path -- like I did in read-cache.c for the "do_read_index" >> calls. >> >> ... | region_enter | ... | index | label:do_read_index .git/index >> ... >> ... | region_leave | ... | index | label:do_read_index .git/index > > Appreciate for the input about the _printf version, we can choose to > let the region_enter and region_leave to print the pathname by moving > the related "midx_bitmap_filename()" and "pack_bitmap_filename" at > front, but it's not enough because both midx and normal bitmap support > multiple opening, so it's likely we keep on the current way using > "trace2_data_string()" in "open_pack_bitmap_1()" and "open_midx_bitmap_1()" > is a simpler solution. > > I'm not sure If I totally get the meaning about your suggestion, > so correct me if I understand you wrong. That's fine. I was assuming that you were only operating on a single file at a time and opening, using, closing it in a nicely bracketed fashion. The region_enter and _leave is good for capturing that. But if you might be handling both files concurrently, then your messages would be better since we don't want mix or improperly nest the regions. (I must admit that I haven't studied the bitmap code, so I defer to your judgement here.) > >> As AEvar suggests in another message in this thread, I'm not sure if >> you need the region timing here for reading the bitmap, but all of >> the error and any other data messages will be bounded between the >> region_enter and region_leave events and that might (or might not) >> be helpful. > > I think it's needed in my opinion, the bounded between the region is > helpful, especially when we want to know the detailed debug info like > we do in "open_midx_bitmap_1()". > > >> Also, I agree with AEvar's statements about using error() and getting >> the trace2 error messages for free and not needing some of the >> trace2_data_string() messages that you have later in this file. >> >> I wonder if it would be worth adding the pathname of the invalid >> file to those new error messages. Granted you'll have it in the >> trace2 log, but then you'll also get it on stderr if that would >> be helpful. > > I think I will remove the redundant "trace2_data_string()" code when > it will return by "error()". > > > Thanks. >
diff --git a/pack-bitmap.c b/pack-bitmap.c index 1b268f655e..a1d06c4252 100644 --- a/pack-bitmap.c +++ b/pack-bitmap.c @@ -312,9 +312,12 @@ char *pack_bitmap_filename(struct packed_git *p) static int open_midx_bitmap_1(struct bitmap_index *bitmap_git, struct multi_pack_index *midx) { + int fd; struct stat st; char *bitmap_name = midx_bitmap_filename(midx); - int fd = git_open(bitmap_name); + trace2_data_string("midx", the_repository, "try to open bitmap", + bitmap_name); + fd = git_open(bitmap_name); free(bitmap_name); @@ -322,6 +325,8 @@ static int open_midx_bitmap_1(struct bitmap_index *bitmap_git, return -1; if (fstat(fd, &st)) { + trace2_data_string("midx", the_repository, "stat bitmap file", + "failed"); close(fd); return -1; } @@ -344,12 +349,19 @@ static int open_midx_bitmap_1(struct bitmap_index *bitmap_git, MAP_PRIVATE, fd, 0); close(fd); - if (load_bitmap_header(bitmap_git) < 0) + if (load_bitmap_header(bitmap_git) < 0) { + trace2_data_string("midx", the_repository, "load bitmap header", + "failed"); goto cleanup; + } - if (!hasheq(get_midx_checksum(bitmap_git->midx), bitmap_git->checksum)) + if (!hasheq(get_midx_checksum(bitmap_git->midx), bitmap_git->checksum)) { + trace2_data_string("midx", the_repository, "verify checksum", + "mismatch"); goto cleanup; + } + if (load_midx_revindex(bitmap_git->midx) < 0) { warning(_("multi-pack bitmap is missing required reverse index")); goto cleanup; @@ -375,6 +387,8 @@ static int open_pack_bitmap_1(struct bitmap_index *bitmap_git, struct packed_git return -1; bitmap_name = pack_bitmap_filename(packfile); + trace2_data_string("bitmap", the_repository, "try to open bitmap", + bitmap_name); fd = git_open(bitmap_name); free(bitmap_name); @@ -382,6 +396,8 @@ static int open_pack_bitmap_1(struct bitmap_index *bitmap_git, struct packed_git return -1; if (fstat(fd, &st)) { + trace2_data_string("bitmap", the_repository, "stat bitmap file", + "failed"); close(fd); return -1; } @@ -395,6 +411,7 @@ static int open_pack_bitmap_1(struct bitmap_index *bitmap_git, struct packed_git } if (!is_pack_valid(packfile)) { + trace2_data_string("bitmap", the_repository, "packfile", "invalid"); close(fd); return -1; } @@ -406,6 +423,8 @@ static int open_pack_bitmap_1(struct bitmap_index *bitmap_git, struct packed_git close(fd); if (load_bitmap_header(bitmap_git) < 0) { + trace2_data_string("bitmap", the_repository, + "load bitmap header", "failed"); munmap(bitmap_git->map, bitmap_git->map_size); bitmap_git->map = NULL; bitmap_git->map_size = 0; @@ -511,11 +530,18 @@ static int open_midx_bitmap(struct repository *r, static int open_bitmap(struct repository *r, struct bitmap_index *bitmap_git) { - assert(!bitmap_git->map); + int ret = -1; - if (!open_midx_bitmap(r, bitmap_git)) - return 0; - return open_pack_bitmap(r, bitmap_git); + assert(!bitmap_git->map); + trace2_region_enter("pack-bitmap", "open_bitmap", r); + if (!open_midx_bitmap(r, bitmap_git)) { + ret = 0; + goto done; + } + ret = open_pack_bitmap(r, bitmap_git); +done: + trace2_region_leave("pack-bitmap", "open_bitmap", r); + return ret; } struct bitmap_index *prepare_bitmap_git(struct repository *r) diff --git a/repo-settings.c b/repo-settings.c index b4fbd16cdc..5bc7a97a6d 100644 --- a/repo-settings.c +++ b/repo-settings.c @@ -8,6 +8,7 @@ static void repo_cfg_bool(struct repository *r, const char *key, int *dest, { if (repo_config_get_bool(r, key, dest)) *dest = def; + trace2_data_string("config", r, key, *dest ? "true" : "false"); } void prepare_repo_settings(struct repository *r) diff --git a/t/t5310-pack-bitmaps.sh b/t/t5310-pack-bitmaps.sh index eb63b71852..664cb88b0b 100755 --- a/t/t5310-pack-bitmaps.sh +++ b/t/t5310-pack-bitmaps.sh @@ -421,8 +421,8 @@ test_expect_success 'complains about multiple pack bitmaps' ' test_line_count = 2 bitmaps && git rev-list --use-bitmap-index HEAD 2>err && - grep "a bitmap has been opened" err && - grep "ignoring extra bitmap file" err + grep "warning: a normal or midx bitmap already has been opened" err && + grep "warning: ignoring extra bitmap file" err ) '
It's supported for a Git repo to use bitmap in both normal bitmap way or a multi-pack-index bitmap. Sometimes the debug path is not obvious, for example, when executing: $git rev-list --test-bitmap HEAD fatal: failed to load bitmap indexes If we see the output like this, we are not sure about what's happened, because the cause should be : 1. neither normal nor midx bitmap exists 2. only midx bitmap exists but core.multipackIndex="false" 3. core.multipackIndex="true" but midx bitmap file is currupt 4. core.multipackIndex="true" and no midx bitmap exists but normal bitmap file is currupt .... These are some of the scenarios I briefly tested, but maybe there are others (some scenarios is produced manually like "currupt bitmap file", but it's not represent it's an existed bug.). Therefore, we added some TRACE2 code so that when we read the bitmap we can be more clear about the decision path, such as whether it is working on midx bitmap or normal bitmap, or is it simply because the related configuration is disabled. This may help with logging, user troubleshooting, and development debugging. Here are some output examples when executing "$GIT_TRACE2_PERF=1 git rev-list --test-bitmap HEAD" under different situations: 1. _HAVE_ MIDX bitmap and NORMAL bitmap file, but the "core.multipackIndex" configures as "false": 19:38:43.007840 common-main.c:49 | d0 | main | version | | | | | 2.35.1.582.g8e9092487a 19:38:43.007874 common-main.c:50 | d0 | main | start | | 0.000305 | | | /opt/git/master/bin/git rev-list --test-bitmap HEAD 19:38:43.007950 compat/linux/procinfo.c:170 | d0 | main | cmd_ancestry | | | | | ancestry:[bash sshd sshd sshd systemd] 19:38:43.008091 git.c:460 | d0 | main | cmd_name | | | | | rev-list (rev-list) 19:38:43.008284 repo-settings.c:11 | d0 | main | data | r0 | 0.000720 | 0.000720 | config | feature.manyfiles:false 19:38:43.008297 repo-settings.c:11 | d0 | main | data | r0 | 0.000734 | 0.000734 | config | feature.experimental:false 19:38:43.008305 repo-settings.c:11 | d0 | main | data | r0 | 0.000742 | 0.000742 | config | core.commitgraph:true 19:38:43.008313 repo-settings.c:11 | d0 | main | data | r0 | 0.000749 | 0.000749 | config | commitgraph.readchangedpaths:true 19:38:43.008320 repo-settings.c:11 | d0 | main | data | r0 | 0.000756 | 0.000756 | config | gc.writecommitgraph:true 19:38:43.008327 repo-settings.c:11 | d0 | main | data | r0 | 0.000764 | 0.000764 | config | fetch.writecommitgraph:false 19:38:43.008334 repo-settings.c:11 | d0 | main | data | r0 | 0.000770 | 0.000770 | config | pack.usesparse:true 19:38:43.008341 repo-settings.c:11 | d0 | main | data | r0 | 0.000777 | 0.000777 | config | core.multipackindex:false 19:38:43.008348 repo-settings.c:11 | d0 | main | data | r0 | 0.000784 | 0.000784 | config | index.sparse:false 19:38:43.008724 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001160 | | pack-bitmap | label:open_bitmap 19:38:43.008738 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001173 | 0.000013 | bitmap | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap 19:38:43.008754 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001191 | 0.000031 | pack-bitmap | label:open_bitmap Bitmap v1 test (8 entries loaded) Found bitmap for 0a7df7ae92f8d8ed879c240f8ae9cdd33d18085e. 64 bits / 1801edc6 checksum 19:38:43.009099 progress.c:268 | d0 | main | region_enter | r0 | 0.001535 | | progress | label:Verifying bitmap entries Verifying bitmap entries: 100% (27/27), done. 19:38:43.009294 progress.c:339 | d0 | main | data | r0 | 0.001730 | 0.000195 | progress | ..total_objects:27 19:38:43.009302 progress.c:346 | d0 | main | region_leave | r0 | 0.001739 | 0.000204 | progress | label:Verifying bitmap entries OK! 19:38:43.009321 git.c:718 | d0 | main | exit | | 0.001757 | | | code:0 19:38:43.009329 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001766 | | | code:0 2. _HAVE_ MIDX bitmap and NORMAL bitmap file, but the "core.multipackIndex" configures as "true": (omit duplicate outputs) ... 20:02:31.288797 repo-settings.c:11 | d0 | main | data | r0 | 0.000811 | 0.000811 | config | core.multipackindex:true 20:02:31.288806 repo-settings.c:11 | d0 | main | data | r0 | 0.000819 | 0.000819 | config | index.sparse:false 20:02:31.288836 midx.c:185 | d0 | main | data | r0 | 0.000849 | 0.000849 | midx | load/num_packs:1 20:02:31.288843 midx.c:186 | d0 | main | data | r0 | 0.000857 | 0.000857 | midx | load/num_objects:27 20:02:31.289217 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001229 | | pack-bitmap | label:open_bitmap 20:02:31.289230 pack-bitmap.c:318 | d0 | main | data | r0 | 0.001242 | 0.000013 | midx | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/multi-pack-index-b6b04fbe053bd500d9ca13354466d3249dc275ac.bitmap 20:02:31.289252 pack-revindex.c:315 | d0 | main | data | r0 | 0.001265 | 0.000036 | load_midx_re | ..source:midx 20:02:31.289261 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001274 | 0.000045 | pack-bitmap | label:open_bitmap Bitmap v1 test (8 entries loaded) Found bitmap for 0a7df7ae92f8d8ed879c240f8ae9cdd33d18085e. 64 bits / 1801edc6 checksum 20:02:31.289594 progress.c:268 | d0 | main | region_enter | r0 | 0.001607 | | progress | label:Verifying bitmap entries Verifying bitmap entries: 100% (27/27), done. 20:02:31.289810 progress.c:339 | d0 | main | data | r0 | 0.001823 | 0.000216 | progress | ..total_objects:27 20:02:31.289824 progress.c:346 | d0 | main | region_leave | r0 | 0.001837 | 0.000230 | progress | label:Verifying bitmap entries OK! 20:02:31.289843 git.c:718 | d0 | main | exit | | 0.001856 | | | code:0 20:02:31.289860 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001873 | | | code:0 3. _HAVE_ MIDX bitmap and a corrupt NORMAL bitmap file, but the "core.multipackIndex" configures as "false" : (omit duplicate outputs) ... 20:14:06.539305 repo-settings.c:11 | d0 | main | data | r0 | 0.000794 | 0.000794 | config | core.multipackindex:false 20:14:06.539310 repo-settings.c:11 | d0 | main | data | r0 | 0.000799 | 0.000799 | config | index.sparse:false 20:14:06.539658 pack-bitmap.c:536 | d0 | main | region_enter | r0 | 0.001146 | | pack-bitmap | label:open_bitmap 20:14:06.539671 pack-bitmap.c:390 | d0 | main | data | r0 | 0.001160 | 0.000014 | bitmap | ..try to open bitmap:/home/tenglong.tl/test/dyrone/.git/objects/pack/pack-2d1b3f749fb859b874710e33263d0847ef009e03.bitmap 20:14:06.539686 usage.c:79 | d0 | main | error | | | | | ..Corrupted bitmap index file (wrong header) error: Corrupted bitmap index file (wrong header) 20:14:06.539696 pack-bitmap.c:426 | d0 | main | data | r0 | 0.001185 | 0.000039 | bitmap | ..load bitmap header:failed 20:14:06.539709 usage.c:79 | d0 | main | error | | | | | ..bitmap header is invalid error: bitmap header is invalid 20:14:06.539719 pack-bitmap.c:543 | d0 | main | region_leave | r0 | 0.001208 | 0.000062 | pack-bitmap | label:open_bitmap 20:14:06.539726 usage.c:60 | d0 | main | error | | | | | failed to load bitmap indexes fatal: failed to load bitmap indexes 20:14:06.539735 usage.c:74 | d0 | main | exit | | 0.001224 | | | code:128 20:14:06.539744 trace2/tr2_tgt_perf.c:215 | d0 | main | atexit | | 0.001233 | | | code:128 Signed-off-by: Teng Long <dyroneteng@gmail.com> --- pack-bitmap.c | 40 +++++++++++++++++++++++++++++++++------- repo-settings.c | 1 + t/t5310-pack-bitmaps.sh | 4 ++-- 3 files changed, 36 insertions(+), 9 deletions(-)