vbauerster / mpb

multi progress bar for Go cli applications
The Unlicense
2.29k stars 123 forks source link

ETA is not accurate; could use help #46

Closed dsoprea closed 5 years ago

dsoprea commented 5 years ago

The ETA isn't working correctly. It's initially non-zero, but drops to zero and stays there for most of the duration. I have a wrapper around theio.Reader that iteratively provides counts and durations. The durations are in the microsecond range.

The documentation for the timing arguments is very terse and, simple person that I am, the examples don't expand the understanding in any way that'd help to debug. I'd appreciate some assistance.

Implementation (based on the example):

progress := mpb.New()

bar := progress.AddBar(
    fi.Size(),

    mpb.PrependDecorators(
        // display our name with one space on the right
        decor.Name(
            currentFilepath,
            decor.WC{W: len(currentFilepath) + 1, C: decor.DidentRight}),

        // replace ETA decorator with "done" message, OnComplete event
        decor.OnComplete(
            // ETA decorator with ewma age of 60, and width reservation of 4
            decor.EwmaETA(decor.ET_STYLE_GO, 60, decor.WC{W: 4}), "done",
        ),
    ),

    mpb.AppendDecorators(decor.Percentage()),
)

progressCb = func(n int, duration time.Duration, isEof bool) error {
    bar.IncrBy(n, duration)
    return nil
}

I'm trying to understand how the ETA is supposed to work, but it's not clear, at least to me, from the documentation.

Output:

$ time go run cmd/gozp/main.go -f /tmp/big.gzp file.mp4
file.mp4   0s [==============================================>-------------------------------] 60 %
^Csignal: interrupt

real    0m12.364s
user    0m12.862s
sys 0m0.356s

This has at least another ten or twenty seconds to go at the 60% mark, but it dropped to (0) right after starting.

dsoprea commented 5 years ago

Same thing with decompression:

$ time go run cmd/guzp/main.go /tmp/big.gzp -o /tmp
file.mp4 81 % [==============================================================>---------------] 0s
home/dustin/Downloads/go1.11.4.linux-amd64.tar.gz 57 % [============================================>---------------------------------] 0s
^Csignal: interrupt

real    0m5.170s
user    0m10.581s
sys 0m0.653s
progressBar := progress.AddBar(
    0,

    mpb.PrependDecorators(
        // simple name decorator
        decor.Name(relFilepath),

        // decor.DSyncWidth bit enables column width synchronization
        decor.Percentage(decor.WCSyncSpace),
    ),

    mpb.AppendDecorators(
        // replace ETA decorator with "done" message, OnComplete event
        decor.OnComplete(

            // ETA decorator with ewma age of 60
            decor.EwmaETA(decor.ET_STYLE_GO, 60), "done",
        ),
    ),
)

// ...

progressBar.SetTotal(int64(uncompressedSize), false)

// ...

for {
// ...
progressBar.IncrBy(writtenCount, time.Since(startAt))
// ...
}

This is a multi-bar setup. The bars aren't synced, either (contributes to the ETA problem?).

dsoprea commented 5 years ago

It's because the decor.EwmaETA() decorators were only part of the OnComplete decorator, which came from both examples. Once I moved it to be a first-class argument to PrependDecorators, for both compression and decompression, it worked fine:

progressBar := progress.AddBar(
    0,

    mpb.PrependDecorators(
        // Add our name.
        decor.Name(
            relFilepath,

            // Add space after the name.
            decor.WC{W: len(relFilepath) + 1, C: decor.DidentRight}),

        decor.Counters(
            decor.UnitKB,
            " %d/%d ",
        ),

        decor.EwmaETA(decor.ET_STYLE_MMSS, 60),
    ),

    mpb.AppendDecorators(
        decor.Percentage(),
    ),
)

It also took me a couple of passes to understand why the size/progress of the bar would jump near the end. It seemed like a math glitch somewhere (whether the user's or this project's). It looks like that's just the progress bars doing lazy syncing of their sizes. Is there some way that I can get bars to be correctly sized from the beginning to prevent the slight resizing that happens near the end?

vbauerster commented 5 years ago

Hi! The key point for EwmaETA decorator to work correctly is family of Incr methods:

You have to pass incremental duration as second parameter. Following snippet shows correct usage, note that start var is set inside the for loop, not outside.

for {
  start := time.Now()
  // actual work, where you get writtenCount
  progressBar.IncrBy(writtenCount, time.Since(start))
}

It's not clear from your snippets how do you calculate duration for IncrBy method, but it looks like you set your start var outside of loop. Also fyi, there is AverageETA decorator, which doesn't require duration to be passed.

vbauerster commented 5 years ago

There is a TimeNormalizer option you can use with MovingAverageETA, see example here. EwmaETA is a wrapper of MovingAverageETA with no TimeNormalizer. It is crucial for any ewma based decorator to supply correct age parameter. I recommend to refer to ewma lib, which is used under the hood, in order to understand what the age is.