{"thread":{"id":"55478","subject":"[PATCH] pack-objects: update \"nr_seen\" progress based on pack-reused count","startedAt":"2021-04-12T03:41:36Z","lastAt":"2021-04-13T07:39:43Z","messageCount":3,"participants":["Jeff King","Derrick Stolee"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"421635","messageId":"YHPBXu9R/7i1jZhy@coredump.intra.peff.net","threadId":"55478","inReplyTo":null,"subject":"[PATCH] pack-objects: update \"nr_seen\" progress based on pack-reused count","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-04-12T03:41:18Z","receivedAt":"2021-04-12T03:41:36Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"When serving a clone or fetch with bitmaps, after deciding which objects\nneed to be sent our \"pack reuse\" mechanism kicks in: we try to send\nmore-or-less verbatim a bunch of objects from the beginning of the\nbitmapped packfile without even adding them to the to_pack.objects\narray.\n\nAfter deciding which objects will be in the \"reused\" portion, we update\nnr_result to account for those, and then trigger display_progress() to\nshow the user (who is undoubtedly dazzled that we managed to enumerate\nso many objects so quickly).\n\nBut then something confusing happens: the \"Enumerating objects\" progress\nmeter jumps _backwards_, counting up from zero the number of objects we\nactually add into to_pack.objects.\n\nThis worked correctly once upon a time, but was broken in 5af050437a\n(pack-objects: show some progress when counting kept objects,\n2018-04-15), when the latter half of that progress meter switched to\nusing a separate nr_seen counter, rather than nr_result. Nobody noticed\nfor two reasons:\n\n  - prior to the pack-reuse fixes from a14aebeac3 (Merge branch\n    'jk/packfile-reuse-cleanup', 2020-02-14), the reuse code almost\n    never kicked in anyway\n\n  - the output looks _kind of_ correct. The \"backwards\" moment is hard\n    to catch, because we overwrite the old progress number with the new\n    one, and the larger number is displayed only for a second. So unless\n    you look at that exact second, you just see the much smaller value,\n    counting up to the number of non-reused objects (though of course if\n    you catch it in stderr, or look at GIT_TRACE_PACKET from a server\n    with bitmaps, you can see both values).\n\nThis smaller output isn't wrong per se, but isn't counting what we ever\nintended to. We should give the user the whole number of objects we\nconsidered (which, as per 5af050437a's original purpose, is already\n_not_ a count of what goes into to_pack.objects). The follow-on\n\"Counting objects\" meter shows the actual number of objects we feed into\nthat array.\n\nWe can easily fix this by bumping (and showing) nr_seen for the\npack-reused objects. When the included test is run without this patch,\nthe second pack-objects invocation produces \"Enumerating objects: 1\" to\nshow the one loose object, even though the resulting pack has hundreds\nof objects in it. With it, we jump to \"Enumerating objects: 674\" after\ndeciding on reuse, and then \"675\" when we add in the loose object.\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\n builtin/pack-objects.c  |  3 ++-\n t/t5310-pack-bitmaps.sh | 23 +++++++++++++++++++++++\n 2 files changed, 25 insertions(+), 1 deletion(-)\n\ndiff --git a/builtin/pack-objects.c b/builtin/pack-objects.c\nindex 525c2d8552..faee5a5c76 100644\n--- a/builtin/pack-objects.c\n+++ b/builtin/pack-objects.c\n@@ -3527,7 +3527,8 @@ static int get_object_list_from_bitmap(struct rev_info *revs)\n \t\t\t&reuse_packfile_bitmap)) {\n \t\tassert(reuse_packfile_objects);\n \t\tnr_result += reuse_packfile_objects;\n-\t\tdisplay_progress(progress_state, nr_result);\n+\t\tnr_seen += reuse_packfile_objects;\n+\t\tdisplay_progress(progress_state, nr_seen);\n \t}\n \n \ttraverse_bitmap_commit_list(bitmap_git, revs,\ndiff --git a/t/t5310-pack-bitmaps.sh b/t/t5310-pack-bitmaps.sh\nindex 40b9f63244..8d0933b6e5 100755\n--- a/t/t5310-pack-bitmaps.sh\n+++ b/t/t5310-pack-bitmaps.sh\n@@ -461,6 +461,29 @@ test_expect_success 'truncated bitmap fails gracefully (cache)' '\n \ttest_i18ngrep corrupted.bitmap.index stderr\n '\n \n+test_expect_success 'enumerating progress counts pack-reused objects' '\n+\tcount=$(git rev-list --objects --all --count) &&\n+\tgit repack -adb &&\n+\n+\t# check first with only reused objects; confirm that our progress\n+\t# showed the right number, and also that we did pack-reuse as expected.\n+\t# Check only the final \"done\" line of the meter (there may be an\n+\t# arbitrary number of intermediate lines ending with CR).\n+\tGIT_PROGRESS_DELAY=0 \\\n+\t\tgit pack-objects --all --stdout --progress \\\n+\t\t</dev/null >/dev/null 2>stderr &&\n+\tgrep \"Enumerating objects: $count, done\" stderr &&\n+\tgrep \"pack-reused $count\" stderr &&\n+\n+\t# now the same but with one non-reused object\n+\tgit commit --allow-empty -m \"an extra commit object\" &&\n+\tGIT_PROGRESS_DELAY=0 \\\n+\t\tgit pack-objects --all --stdout --progress \\\n+\t\t</dev/null >/dev/null 2>stderr &&\n+\tgrep \"Enumerating objects: $((count+1)), done\" stderr &&\n+\tgrep \"pack-reused $count\" stderr\n+'\n+\n # have_delta <obj> <expected_base>\n #\n # Note that because this relies on cat-file, it might find _any_ copy of an\n-- \n2.31.1.657.gecf191e18d\n"},{"id":"421827","messageId":"06e42cf3-188c-d314-b3b9-bdb2f43a37e6@gmail.com","threadId":"55478","inReplyTo":"YHPBXu9R/7i1jZhy@coredump.intra.peff.net","subject":"Re: [PATCH] pack-objects: update \"nr_seen\" progress based on pack-reused count","fromName":"Derrick Stolee","fromEmail":"stolee@gmail.com","sentAt":"2021-04-13T00:48:24Z","receivedAt":"2021-04-13T00:48:30Z","isPatch":true,"sender":{"key":"stolee@gmail.com","avatar":"https://avatars.githubusercontent.com/u/570044?v=4"},"body":"On 4/11/2021 11:41 PM, Jeff King wrote:> diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c\n> index 525c2d8552..faee5a5c76 100644\n> --- a/builtin/pack-objects.c\n> +++ b/builtin/pack-objects.c\n> @@ -3527,7 +3527,8 @@ static int get_object_list_from_bitmap(struct rev_info *revs)\n>  \t\t\t&reuse_packfile_bitmap)) {\n>  \t\tassert(reuse_packfile_objects);\n>  \t\tnr_result += reuse_packfile_objects;\n> -\t\tdisplay_progress(progress_state, nr_result);\n> +\t\tnr_seen += reuse_packfile_objects;\n> +\t\tdisplay_progress(progress_state, nr_seen);\n\nnr_seen and nr_result are defined in the same line with nr_written,\nas static globals. I can understand how this mistake happened.\n\nThere are no other places where nr_result is used for\ndisplay_progress() while nr_seen _is_ used a couple more times.\n\n> +test_expect_success 'enumerating progress counts pack-reused objects' '\n> +\tcount=$(git rev-list --objects --all --count) &&\n> +\tgit repack -adb &&\n> +\n> +\t# check first with only reused objects; confirm that our progress\n> +\t# showed the right number, and also that we did pack-reuse as expected.\n> +\t# Check only the final \"done\" line of the meter (there may be an\n> +\t# arbitrary number of intermediate lines ending with CR).\n> +\tGIT_PROGRESS_DELAY=0 \\\n> +\t\tgit pack-objects --all --stdout --progress \\\n> +\t\t</dev/null >/dev/null 2>stderr &&\n> +\tgrep \"Enumerating objects: $count, done\" stderr &&\n> +\tgrep \"pack-reused $count\" stderr &&\n> +\n> +\t# now the same but with one non-reused object\n> +\tgit commit --allow-empty -m \"an extra commit object\" &&\n> +\tGIT_PROGRESS_DELAY=0 \\\n> +\t\tgit pack-objects --all --stdout --progress \\\n> +\t\t</dev/null >/dev/null 2>stderr &&\n> +\tgrep \"Enumerating objects: $((count+1)), done\" stderr &&\n> +\tgrep \"pack-reused $count\" stderr\n> +'\n\nGood test. LGTM.\n\nThanks,\n-Stolee\n"},{"id":"421844","messageId":"YHVKuFaR/AjYhf9b@coredump.intra.peff.net","threadId":"55478","inReplyTo":"06e42cf3-188c-d314-b3b9-bdb2f43a37e6@gmail.com","subject":"Re: [PATCH] pack-objects: update \"nr_seen\" progress based on pack-reused count","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-04-13T07:39:36Z","receivedAt":"2021-04-13T07:39:43Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Apr 12, 2021 at 08:48:24PM -0400, Derrick Stolee wrote:\n\n> On 4/11/2021 11:41 PM, Jeff King wrote:> diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c\n> > index 525c2d8552..faee5a5c76 100644\n> > --- a/builtin/pack-objects.c\n> > +++ b/builtin/pack-objects.c\n> > @@ -3527,7 +3527,8 @@ static int get_object_list_from_bitmap(struct rev_info *revs)\n> >  \t\t\t&reuse_packfile_bitmap)) {\n> >  \t\tassert(reuse_packfile_objects);\n> >  \t\tnr_result += reuse_packfile_objects;\n> > -\t\tdisplay_progress(progress_state, nr_result);\n> > +\t\tnr_seen += reuse_packfile_objects;\n> > +\t\tdisplay_progress(progress_state, nr_seen);\n> \n> nr_seen and nr_result are defined in the same line with nr_written,\n> as static globals. I can understand how this mistake happened.\n\nI think it is even more subtle than that. Both topics (the one to\nconvert callers to use nr_seen as progress, and the one adding this call\nto use nr_result for progress) were \"in flight\" at the same time, but in\na funny way. The latter was written much earlier in a fork of Git, but\nnot sent upstream immediately. So the nr_seen conversion didn't know\nabout it, and later the other topic was \"merged\" (actually,\ncherry-picked) into upstream.\n\nSo it really is a semantic conflict when merging two branches that\nhappened simultaneously. It's a little odd in that the branches were\nrunning simultaneously for years, but the same thing could happen even\nwith two topics much closer together.\n\nAnyway, that's all just an interesting sidenote.\n\n> There are no other places where nr_result is used for\n> display_progress() while nr_seen _is_ used a couple more times.\n\nThanks for double-checking. That make sense, since we added only this\none call, and the others were all converted to nr_seen when it was\nintroduced.\n\n-Peff\n"}]}