Repository navigation
Conversation
A background or redirected run printed nothing until the final summary, so a six-hour report looked hung. Off a TTY, offload, report and verify now write newline-terminated lines (percent, files, name, throughput, ETA): one per file start (at most one a second), one every 30 s, and one on completion. The single-line bar on a TTY and --quiet behave as before.
owenpkent
left a comment
owenpkent
left a comment
There was a problem hiding this comment.
Found two P2 issues in the new non-TTY progress output. The inline comments cover missing updates during long hashes and a verification percentage that reaches 100% before the final file has been read.
Reviewed all four changed files and traced the CLI callbacks through engine.run, engine.rescan, verify_manifest, hash_file, retry handling, and the affected tests. Base and merge-base: e01a0eb. Head: b1279b3. No prior discussion or review threads were present.
Validation:
- 103 focused tests passed in an isolated detached worktree on Windows/Python 3.12.10: test_cli.py, test_verify.py, test_engine.py, test_data_safety.py, and test_retry.py.
- Reproduced both findings through the actual CLI and real checksum reads using a synthetic 4 KiB file, a reader capped at 1 KiB per chunk, and a clock advanced by 31 seconds per chunk. No production code was changed.
- All nine reported checks for the reviewed head succeeded, including Windows/Linux/macOS tests, Python 3.10 coverage, ffmpeg coverage, property-test soak, and distribution build. See the CI run.
Long-file timing was simulated deterministically; no physical camera media or hours-long hardware transfer was tested. This review does not establish coverage beyond the inspected paths.
| due = now - self._last_log >= LOG_INTERVAL | ||
| started = new_file and now - self._last_start >= LOG_START_GAP | ||
| finished = final and not self._logged_final | ||
| if not (due or started or finished): | ||
| return |
There was a problem hiding this comment.
[P2] Connect periodic logging to progress during hashing
LOG_INTERVAL is checked only when a progress callback arrives. engine.rescan() calls progress once before hash_file() for each file, and hash_file() emits no callbacks while reading. verify_manifest() and the full-verification read in engine.run() have the same gap. A large camera clip that takes minutes to hash therefore still leaves the log silent for that entire read, which is the long-running background workflow this change is intended to make observable.
I reproduced this through the real report command with four checksum reads and a clock advancing 31 seconds per read: stderr contained only [ 0.0%] verify 1/1 clip.mov from start through completion, with no periodic update. rescan() also never emits its final byte count, so this path produces no completion progress line either. The standalone verify command likewise emitted no additional lines during the 124 simulated seconds.
Pass byte-progress callbacks through the hashing loop, or provide a timer-based heartbeat, and publish completed progress when the operation finishes. Add an integration test that advances beyond LOG_INTERVAL while a single file is still being hashed; the current tests manually invoke progress again or only check that some output exists.
There was a problem hiding this comment.
Fixed: hash_file now takes an optional on_bytes callback (called per chunk, default None), wired into rescan, the full-verify read in run() and verify_manifest, so periodic lines fire mid-file. rescan also emits its final count, so report logs a 100% line. Tests advance a fake clock per chunk and fail without the change.
| pct = (index + 1) / total * 100 if total else 100.0 | ||
| sys.stderr.write(f"[{pct:5.1f}%] verify {index + 1}/{total} {path.name}\n") |
There was a problem hiding this comment.
[P2] Calculate verification percentage from completed work
verify_manifest() invokes this callback at the start of each entry, before checking the path, evicting its cache, or calling hash_file() (verify.py:177-194). Using index + 1 as the completed count therefore reports 100% as soon as the final file starts. For a one-file manifest, I observed [100.0%] verify 1/1 clip.mov inside the reader before its first read; the entire checksum calculation was still outstanding.
With a large final clip, the redirected log advertises complete verification for the duration of that read, even though the file can subsequently fail. Track completed files or bytes and reserve 100% for completion, or explicitly label this callback as starting the current file instead of presenting it as completed progress. Add a regression that inspects stderr while the first hash is in progress and verifies that 100% appears only after the final hash returns.
There was a problem hiding this comment.
Fixed: verify percent is now files completed plus the share of the current file read, capped at 99.9 mid-run; 100% is logged only after verify_manifest returns. Regression inspects stderr during the hash and asserts no 100% appears until afterwards.
…ntil done hash_file takes an optional on_bytes callback, called per chunk, which rescan, the full-verification read in run() and verify_manifest use so the periodic log line fires during one very large file. rescan now emits its final byte count, and verify computes percent from completed work and logs 100% only after the last hash returns.
A redirected or background run printed no progress until the final summary, so a long
offloader reportlooked hung.Off a TTY (and without
--quiet),offload,reportandverifynow write plain newline-terminated lines: one when a file starts (at most one per second), one every 30 s, and one on completion, with percent of job bytes, files done/total, file name, throughput and ETA. The TTY bar is unchanged;--quietsilences both.Verified: full pytest (410 passed, 3 skipped), ruff clean. New tests cover the non-TTY lines, throttling, quiet, and the report and verify commands end to end. The old test asserting
enabledis False off a TTY was replaced, sinceenablednow means not quiet.