Re: non-smooth progress indication for git fsck and git gc

["Ævar Arnfjörð Bjarmason" <avarab@gmail.com>]

On Thu, Aug 16 2018, Jeff King wrote:

> On Thu, Aug 16, 2018 at 08:54:25AM +0200, Ulrich Windl wrote:
>
>> I'd like to point out some minor issue observed while processing some
>> 50000-object repository with many binary objects, but most are rather
>> small:
>>
>> Between the two phases of "git fsck" (checking directories and
>> checking objects) there was a break of several seconds where no
>> progress was indicated.
>>
>> During "git gc" the writing objects phase did not update for some
>> seconds, but then the percentage counter jumped like from 15% to 42%.
>>
>> I understand that updating the progress output too often can be a
>> performance bottleneck, while upating it too rarely might only bore
>> the user... ;-)
>
> We update the counter integer for every object we process, and then
> actually update the display whenever the percentage increases or a
> second has elapsed, whichever comes first.
>
> What you're seeing is likely an artifact of _what_ we're counting:
> written objects. Not all objects are the same size, so it's not uncommon
> to see thousands/sec when dealing with small ones, and then several
> seconds for one giant blob.
>
> The only way to solve that is to count bytes. We don't have a total byte
> count in most cases, and it wouldn't always make sense (e.g., the
> "Compressing objects" meter can show the same issue, but it's not really
> putting through bytes in a linear way).  In some cases we do show
> transmitted size and throughput, but that's just for network operations.
> We could do the same for "gc" with the patch below. But usually
> throughput isn't all that interesting for a filesystem write, because
> bandwidth isn't the bottleneck.
>
> Possibly we could have a "half throughput" mode that counts up the total
> size written, but omits the speed indicator. That's not an unreasonable
> thing to show for a local pack, since you end up with the final pack
> size. The object counter would still be jumpy, but you'd at least have
> one number updated at least once per second as you put through a large
> blob.
>
> If you really want a smooth percentage, then we'd have to start counting
> bytes instead of objects. Two reasons we don't do that are:
>
>   - we often don't know the total byte size exactly. E.g., for a
>     packfile write, it depends on the result of deflating each object.
>     You can make an approximation and just pretend at the end that you
>     hit 100%.  Or you can count the pre-deflate sizes, but then your
>     meter doesn't match the bytes from the throughput counter.
>
>   - for something like fsck, we're not actually writing out bytes.  So I
>     guess you'd be measuring "here's how many bytes of objects I
>     fsck-ed". But is that on-disk compressed bytes, or decompressed
>     bytes?
>
>     If the former, that's only marginally better as a measure of effort,
>     since delta compression means that a small number of on-disk bytes
>     may require a big effort (imagine processing a 100 byte blob versus
>     a 100 byte delta off of a 100MB blob).
>
>     The latter is probably more accurate. But it's also not free to
>     pre-generate the total. We can get the number of objects or the size
>     of the packfile in constant-time, but totaling up the uncompressed
>     size of all objects is O(n). So that's extra computation, but it
>     also means a potential lag before we can start the progress meter.
>
>     I'm also not sure how meaningful a byte count is for a user there.
>
> So there. That's probably more than you wanted to know about Git's
> progress code. I think it probably _could_ be improved by counting
> more/different things, but I also think it can be a bit of a rabbit
> hole. Which is why AFAIK nobody's really looked too seriously into
> changing it.
>
> -Peff

This is all interesting, but I think unrelated to what Ulrich is talking
about. Quote:

    Between the two phases of "git fsck" (checking directories and
    checking objects) there was a break of several seconds where no
    progress was indicated

I.e. it's not about the pause you get with your testcase (which is
certainly another issue) but the break between the two progress bars.

Here's a test case you can clone:
https://github.com/avar/2015-04-03-1M-git (or might already have
"locally" :)

If you fsck this repository it'll take around (on my spinning rust
server) 30 seconds between 100% of "Checking object directories" before
you get any output from "Checking objects".

The breakdown of that is (this is from approximate eyeballing):

 * We spend 1-3 seconds just on this:
   https://github.com/git/git/blob/63749b2dea5d1501ff85bab7b8a7f64911d21dea/pack-check.c#L181

 * We spend the majority of the ~30s on this:
   https://github.com/git/git/blob/63749b2dea5d1501ff85bab7b8a7f64911d21dea/pack-check.c#L70-L79

 * Wes spend another 3-5 seconds on this QSORT:
   https://github.com/git/git/blob/63749b2dea5d1501ff85bab7b8a7f64911d21dea/pack-check.c#L105

I.e. it's not about objects v.s. bytes, but the structural problem with
the code that we pass a progress bar down to verify_pack() which does a
lot of work in verify_pack_index() and verify_packfile() before we even
get to iterating over the objects in the file, and only then do we start
displaying progress.