refactor(general): Increase restore progress granularity #3655

e-sumin · 2024-02-18T17:52:42Z

When restoring huge file(s), the progress reporting is done in a bit weird way:

kopia_test % kopia snapshot restore ka2084d263182164b6cf3456668e6b6da /Users/eugen.sumin/kopia_test/2
Restoring to local filesystem (/Users/eugen.sumin/kopia_test/2) with parallelism=8...
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.6 MB/s (100.0%) remaining 0s.
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.6 MB/s (100.0%) remaining 0s.
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.6 MB/s (100.0%) remaining 0s.
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.5 MB/s (100.0%) remaining 0s.
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.5 MB/s (100.0%) remaining 0s.
Processed 6 (5.4 GB) of 5 (5.4 GB) 1.5 MB/s (100.0%) remaining 0s.
Restored 5 files, 1 directories and 0 symbolic links (5.4 GB).

In fact, the amount of restored data is dumped when particular file completely restored.

This PR contains the least invasive change, which allows us to see progress update while file is downloaded from object storage.

Restoring to local filesystem (/Users/eugen.sumin/kopia_test/55) with parallelism=8...
Processed 2 (3.1 MB) of 5 (1.8 GB).
Processed 4 (459.6 MB) of 5 (1.8 GB) 270.3 MB/s (25.2%) remaining 4s.
Processed 4 (468.7 MB) of 5 (1.8 GB) 269 MB/s (25.7%) remaining 4s.
Processed 4 (741.6 MB) of 5 (1.8 GB) 269 MB/s (40.6%) remaining 3s.
Processed 4 (1.1 GB) of 5 (1.8 GB) 280 MB/s (57.6%) remaining 2s.
Processed 5 (1.4 GB) of 5 (1.8 GB) 291.1 MB/s (75.2%) remaining 1s.
Processed 5 (1.4 GB) of 5 (1.8 GB) 289.8 MB/s (75.6%) remaining 1s.
Processed 5 (1.6 GB) of 5 (1.8 GB) 270.2 MB/s (85.3%) remaining 0s.
Processed 5 (1.7 GB) of 5 (1.8 GB) 256.3 MB/s (95.0%) remaining 0s.
Processed 6 (1.8 GB) of 5 (1.8 GB) 251 MB/s (100.0%) remaining 0s.
Processed 6 (1.8 GB) of 5 (1.8 GB) 251 MB/s (100.0%) remaining 0s.
Restored 5 files, 1 directories and 0 symbolic links (1.8 GB).

e-sumin · 2024-02-18T17:53:39Z

@KastenMike @julio-lopez could you please review ?

jkowalski · 2024-02-19T03:32:57Z

repo/object/object_reader.go

@@ -35,6 +35,10 @@ func VerifyObject(ctx context.Context, cr contentReader, oid ID) ([]content.ID,
 	return tracker.contentIDs(), nil
 }

+// FileReadingProgressCallback is a callback intended to be used during file copying
+// to report amount of data sent to destination.
+type FileReadingProgressCallback func(chunkSize int64)


why do we need to change object reader at all, can't we just emit the progress as we're reading the bytes during restore?

this does not seem used anywhere, the rest looks good

codecov · 2024-02-19T03:34:22Z

Codecov Report

Attention: Patch coverage is 83.20000% with 21 lines in your changes are missing coverage. Please review.

Project coverage is 77.18%. Comparing base (cb455c6) to head (3b49d9a).
Report is 133 commits behind head on master.

Files	Patch %	Lines
cli/cli_progress.go	77.58%	8 Missing and 5 partials ⚠️
snapshot/restore/local_fs_output.go	63.15%	7 Missing ⚠️
snapshot/restore/restore.go	95.23%	0 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #3655      +/-   ##
==========================================
+ Coverage   75.86%   77.18%   +1.31%     
==========================================
  Files         470      479       +9     
  Lines       37301    28756    -8545     
==========================================
- Hits        28299    22194    -6105     
+ Misses       7071     4660    -2411     
+ Partials     1931     1902      -29

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

jkowalski · 2024-02-19T03:38:37Z

snapshot/restore/local_fs_output.go

@@ -403,6 +404,14 @@ func (o *FilesystemOutput) copyFileContent(ctx context.Context, targetPath strin
 	}
 	defer r.Close() //nolint:errcheck

+	type withProgressTracking interface {


I think it's easier to wrap "r" so that it reports bytes written in the callback.

Thank you for the idea, I've changed the code, is it what you meant ?

e-sumin · 2024-03-04T11:03:26Z

@jkowalski do you think the changes could be merged ? Or something else has to be done before ?

e-sumin · 2024-03-11T15:51:56Z

@jkowalski do you think the changes could be merged ? Or something else has to be done before ?

Don't want to be annoying, just a friendly reminder :)

denisvmedia · 2024-03-28T09:36:34Z

@jkowalski @redgoat650 @julio-lopez could you please check this PR?

Shrekster · 2024-04-03T17:32:05Z

snapshot/restore/local_fs_output.go

 	}

-	return write(targetPath, r, f.Size(), o.copier)
+	return write(targetPath, wr, f.Size(), o.copier)


@e-sumin Question about the progress reporting using the reader tracking mechanism:

What is the best way to evaluate progress, as in the definition of done on processing X bytes ? When we have read X bytes from the reader does that mean we are done writing X bytes to the target ? In other words, would it be possible to get in a scenario where we have read 100% of the data from repository and are still stuck writing the final block due to a network issue (NFS) or similar ?

That's true, but this way of progress update was chosen because it is less intrusive. Also, when reading, usually, the block is very small in comparison with total amount of data. So, we, anyway, can get 100% earlier than last block will be read. So, I'd not consider this as critical flaw.

Shrekster · 2024-04-03T17:42:21Z

snapshot/restore/restore.go

+		bytesWritten := int64(0)
+		progressCallback := func(chunkSize int64) {
+			bytesWritten += chunkSize
+			c.stats.RestoredTotalFileSize.Add(chunkSize)


nit; this callback is hit each time we have read chunkSize from the repository, not necessarily "bytes written". Is that correct ? This is w.r.t. to the my other comment as well.

Yes, that's correct. This progress calculation way treats bytes read as bytes written.

Shrekster · 2024-04-04T20:42:39Z

@e-sumin and I discussed this over a call and he explained why the reader based approach is correct / simpler for now. I also agree with his comments above.

@e-sumin is looking into adding unit-test coverage with a custom test-only callback plumbing to make it non-flaky.

Wrapping is not needed while we are just proxifying requests.

e-sumin · 2024-05-06T10:08:10Z

I did some refactoring of snapshot restore:

progress reporting interval is taken from command line, as it was done for upload progress reporting
- currently upload progress instance is keeping progress flag and interval and restore progress just utilizes its value (this was originally discussed with @Shrekster as less invasive thing)
- cli progress refactoring should be done (but probably it would be better to have it as a separate PR). We need to extract flag and interval and throttling mechanism to reused part and create progress instance depending on operation (upload or restore)
  - this also will allow to write separate tests for progress reporting format and progress reporting intervals
probably it would be better to pass restore progress interface to copier and increase counters separately when needed instead of keeping another copy of stats in copier and passing its values to progress reporter.

Some of changes I've done was done to be able to have an unit test which verifies that progress is reported properly.

…ogress_granularity

e-sumin · 2024-05-09T20:28:41Z

I've fixed the test and merged master into my branch. The tests should pass now.

tests/end_to_end_test/restore_test.go

snapshot/restore/local_fs_output.go

denisvmedia · 2024-05-13T10:02:19Z

snapshot/restore/restore_progress.go

+
+// Progress is invoked by copier to report status of snapshot restoration.
+type Progress interface {
+	SetCounters(


Too late to comment here, but I believe having an args struct would be better.

e-sumin added 2 commits February 13, 2024 12:41

When downloading file from repo, report amount of downloaded bytes

fb76560

Remove redundant counter and add comment

8e63f7e

jkowalski reviewed Feb 19, 2024

View reviewed changes

e-sumin added 3 commits February 26, 2024 22:23

Capture amount of data using wrapper for fs.Reader

ff440e6

Fix crash

5c4e957

Remove redundant callback

ce7bf79

Shrekster reviewed Apr 3, 2024

View reviewed changes

e-sumin added 4 commits May 2, 2024 11:19

Fix issues highlighted by linter.

cd6c798

Wrapping is not needed while we are just proxifying requests.

Refactor restore progress reporting using CLI parameters

e112f4d

Introduce RestoreProgress interface

acd690e

Add restore progress test

88604c3

e-sumin requested a review from Shrekster May 6, 2024 10:08

e-sumin added 2 commits May 9, 2024 22:27

Fix race in tests

a10a3cb

Merge remote-tracking branch 'origin/master' into increase_restore_pr…

a8171ee

…ogress_granularity

Shrekster reviewed May 9, 2024

View reviewed changes

tests/end_to_end_test/restore_test.go Outdated Show resolved Hide resolved

Update tests/end_to_end_test/restore_test.go

0f9140d

Shrekster reviewed May 9, 2024

View reviewed changes

snapshot/restore/local_fs_output.go Show resolved Hide resolved

Update snapshot/restore/local_fs_output.go

3b49d9a

Shrekster approved these changes May 10, 2024

View reviewed changes

Shrekster merged commit 2b92388 into kopia:master May 10, 2024
23 checks passed

denisvmedia reviewed May 13, 2024

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

refactor(general): Increase restore progress granularity #3655

refactor(general): Increase restore progress granularity #3655

e-sumin commented Feb 18, 2024 •

edited

Loading

e-sumin commented Feb 18, 2024

jkowalski Feb 19, 2024

jkowalski Feb 27, 2024

codecov bot commented Feb 19, 2024 •

edited

Loading

jkowalski Feb 19, 2024

e-sumin Feb 26, 2024

e-sumin commented Mar 4, 2024 •

edited

Loading

e-sumin commented Mar 11, 2024

denisvmedia commented Mar 28, 2024

Shrekster Apr 3, 2024

e-sumin Apr 4, 2024

Shrekster Apr 3, 2024 •

edited

Loading

e-sumin Apr 4, 2024

Shrekster commented Apr 4, 2024 •

edited

Loading

e-sumin commented May 6, 2024

e-sumin commented May 9, 2024

denisvmedia May 13, 2024

refactor(general): Increase restore progress granularity #3655

refactor(general): Increase restore progress granularity #3655

Conversation

e-sumin commented Feb 18, 2024 • edited Loading

e-sumin commented Feb 18, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

codecov bot commented Feb 19, 2024 • edited Loading

Codecov Report

Choose a reason for hiding this comment

Choose a reason for hiding this comment

e-sumin commented Mar 4, 2024 • edited Loading

e-sumin commented Mar 11, 2024

denisvmedia commented Mar 28, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Shrekster Apr 3, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Shrekster commented Apr 4, 2024 • edited Loading

e-sumin commented May 6, 2024

e-sumin commented May 9, 2024

Choose a reason for hiding this comment

e-sumin commented Feb 18, 2024 •

edited

Loading

codecov bot commented Feb 19, 2024 •

edited

Loading

e-sumin commented Mar 4, 2024 •

edited

Loading

Shrekster Apr 3, 2024 •

edited

Loading

Shrekster commented Apr 4, 2024 •

edited

Loading