backup progress is inaccurate

[sticnarf]

When I do a full backup, it keeps doing backup and printing progress=100% for a long time after the it first prints progress=100%.

Logs are like this:

[2019/12/20 15:58:26.674 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:26.874 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:27.074 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:27.274 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:27.474 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:27.674 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:27.702 +08:00] [INFO] [client.go:683] ["range backuped"] [StartKey="dIAAAAAAAAFQX3KAAAAAAAZfmw=="] [EndKey="dIAAAAAAAAF
QX3KAAAAAAAvJXQ=="]
[2019/12/20 15:58:27.874 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:28.074 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:28.274 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:28.407 +08:00] [INFO] [client.go:683] ["range backuped"] [StartKey="dIAAAAAAAAFQX3KAAAAAAAvJXQ=="] [EndKey="dIAAAAAAAAF
QX3L//////////wA="]
[2019/12/20 15:58:28.408 +08:00] [INFO] [client.go:676] ["backup streaming finish"] [StoreID=1]
[2019/12/20 15:58:28.408 +08:00] [INFO] [client.go:379] ["finish backup push down"] [Ok=4]
[2019/12/20 15:58:28.408 +08:00] [INFO] [client.go:392] ["backup time range"] [StartVersion=0] [EndVersion=413356152248860683]
[2019/12/20 15:58:28.408 +08:00] [INFO] [client.go:405] ["backup range finished"] [take=3.237989556s]
[2019/12/20 15:58:28.408 +08:00] [INFO] [client.go:349] ["backup started"] [StartKey="dIAAAAAAAAFQX2mAAAAAAAAAAQA="] [EndKey="dIAAAAAAAAFQX2mAAAAAAAAAAfs="] [RateLimit=0] [Concurrency=4]
[2019/12/20 15:58:28.409 +08:00] [INFO] [push.go:24] ["new backup client"]
[2019/12/20 15:58:28.409 +08:00] [INFO] [client.go:664] ["try backup"] ["backup request"="{\"cluster_id\":6771082893009782418,\"start_key\":\"dIAAAAAAAAFQX2mAAAAAAAAAAQA=\",\"end_key\":\"dIAAAAAAAAFQX2mAAAAAAAAAAfs=\",\"end_version\":413356152248860683,\"concurrency\":4,\"storage_backend\":{\"Backend\":{\"Local\":{\"path\":\"/data2/yilin/bak/full\"}}}}"]
[2019/12/20 15:58:28.474 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:28.674 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:28.874 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:29.074 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:29.274 +08:00] [INFO] [progress.go:100] ["Database backup"] [progress=100.00%]
[2019/12/20 15:58:29.385 +08:00] [INFO] [client.go:683] ["range backuped"] [StartKey="dIAAAAAAAAFQX2mAAAAAAAAAAQA="] [EndKey="dIAAAAAAAAFQX2mAAAAAAAAAAfs="]
[2019/12/20 15:58:29.385 +08:00] [INFO] [client.go:676] ["backup streaming finish"] [StoreID=1]