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@xxxxxxxxx>
---
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
