Repository navigation
fix(bench): Fail stalled backup downloads and show their progress - #612
balamurali27 wants to merge 6 commits into
Conversation
download_file called requests.get with no timeout. A receiving socket has no timer of its own, so when the connection went half-open, the restore waited with no data until the 4 hour RQ job timeout killed it. A 4 GB restore from ap-south-1 to Ashburn did this. The server received almost no bytes for hours, after a burst of inbound packet loss. The read timeout of 60 s fails the step when no bytes arrive for that long, so the operator can retry. It does not limit the total time of a slow but moving download. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
The Download Backup Files step showed nothing until it finished. A user who watched a restore could not tell a slow download from a stalled one, so they could not decide to cancel it. The step now publishes one line per file, for example "Private files: 1.20GB of 1.67GB", every 2 s. Press already polls the output of a running step and sends it to the job page, when realtime_job_updates is on in Press Settings. The 2 s interval keeps the redis writes low, because a chunk is only 8 KB for small files. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
|
This pull request does not currently match the merge queue conditions, so it cannot be queued from here. The box comes back if it matches again. |
|
| for chunk in r.iter_content(chunk_size=chunk_size): | ||
| f.write(chunk) | ||
| downloaded += len(chunk) | ||
| if on_progress and time.monotonic() - last_report >= DOWNLOAD_PROGRESS_INTERVAL: | ||
| on_progress(downloaded, total_size) | ||
| last_report = time.monotonic() |
There was a problem hiding this comment.
Large chunks delay progress The callback runs only after
iter_content yields a complete chunk. For backups over 100 MB, a slow but active connection may take minutes to fill a 1 MB chunk, leaving the displayed progress unchanged despite the two-second interval. Use smaller chunks or report received bytes more frequently.
Knowledge Base Used: Jobs and callbacks
Prompt To Fix With AI
This is a comment left during a code review.
Path: agent/utils.py
Line: 88-93
Comment:
**Large chunks delay progress** The callback runs only after `iter_content` yields a complete chunk. For backups over 100 MB, a slow but active connection may take minutes to fill a 1 MB chunk, leaving the displayed progress unchanged despite the two-second interval. Use smaller chunks or report received bytes more frequently.
**Knowledge Base Used:** [Jobs and callbacks](https://app.greptile.com/frappe/-/custom-context/knowledge-base/frappe/agent/-/docs/jobs-and-callbacks.md)
---
For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!
| def download_with_progress(self, url, directory, label, lines): | ||
| """Download url and show one line of progress per file in the step output""" | ||
| if not url: | ||
| return "" | ||
| lines.append(label) | ||
|
|
||
| def publish(downloaded, total): | ||
| lines[-1] = f"{label}: {format_size(downloaded)} of {format_size(total) if total else 'unknown'}" |
There was a problem hiding this comment.
Helper mutates caller-owned list
download_with_progress changes the lines list passed by its caller. The repository guideline prohibits passing mutable objects to be filled in; return the updated progress state instead. This requirement must be satisfied before merging.
Context Used: Guidelines for reviewing Frappe Framework applications. (source)
Prompt To Fix With AI
This is a comment left during a code review.
Path: agent/bench.py
Line: 475-482
Comment:
**Helper mutates caller-owned list** `download_with_progress` changes the `lines` list passed by its caller. The repository guideline prohibits passing mutable objects to be filled in; return the updated progress state instead. This requirement must be satisfied before merging.
**Context Used:** Guidelines for reviewing Frappe Framework applications. ([source](https://github.com/frappe/skills/blob/main/skills/quality-code-review/SKILL.md))
---
For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!
| self.server.daemon_threads = True | ||
| threading.Thread(target=self.server.serve_forever, daemon=True).start() | ||
| self.base_url = f"http://127.0.0.1:{self.server.server_port}" | ||
| self.directory = tempfile.mkdtemp() |
There was a problem hiding this comment.
Tests retain downloaded files Each test creates a temporary download directory, but teardown closes only the server. Repeated runs leave the directory and its downloaded files behind. Remove it in teardown or use
TemporaryDirectory.
Prompt To Fix With AI
This is a comment left during a code review.
Path: agent/tests/test_download_file.py
Line: 40
Comment:
**Tests retain downloaded files** Each test creates a temporary download directory, but teardown closes only the server. Repeated runs leave the directory and its downloaded files behind. Remove it in teardown or use `TemporaryDirectory`.
---
For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.A line with only the byte count does not tell the user if the download will finish soon. The line now has the elapsed time, the average rate, a bar, the percent and the ETA, in the same layout as pv: Private files: 1.20GB 0:07:10 [2.86MB/s] [=====> ] 71% ETA 0:02:48 The rate is the average since the start, as pv uses for its ETA. The job page shows step output in a pre element, so the bar lines up. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
| start = datetime.now() | ||
|
|
||
| def publish(downloaded, total): | ||
| elapsed = (datetime.now() - start).total_seconds() |
There was a problem hiding this comment.
Clock changes distort progress If the system clock moves backward during a long download,
elapsed becomes negative and the published rate and ETA become misleading. Measure elapsed time with a monotonic clock.
Prompt To Fix With AI
This is a comment left during a code review.
Path: agent/bench.py
Line: 480-483
Comment:
**Clock changes distort progress** If the system clock moves backward during a long download, `elapsed` becomes negative and the published rate and ETA become misleading. Measure elapsed time with a monotonic clock.
---
For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.The Checksum of Downloaded Backup Files step runs only when the restore fails, so a successful or a stalled restore showed no checksum. The download step now adds the SHA256 of each file below its progress line. The line uses the format of the checksum step. The step also returns these lines as its output. Before, the output of a step that ended was empty, so the progress was lost. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
Hashing each file after its download reads a 4 GB backup from disk again on every restore. The Checksum of Downloaded Backup Files step already runs when the restore fails, which is when the checksum helps (agent#144). So remove the checksum from the download step. The download step still returns its progress lines as its output, so they stay on the job page after the step ends. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
| lines[-1] = f"{label}: {format_progress(downloaded, total, elapsed)}" | ||
| self.publish_data("\n".join(lines)) | ||
|
|
||
| return download_file(url, prefix=directory, on_progress=publish) |
There was a problem hiding this comment.
Failed restores lose checksums When New Site from Backup fails during restore, this change leaves no checksum record before the downloaded files are deleted. That makes a bad backup harder to diagnose. Preserve failure-path checksums for this workflow, which Press also uses for site migrations.
Knowledge Base Used: Backup and restore
Prompt To Fix With AI
This is a comment left during a code review.
Path: agent/bench.py
Line: 488
Comment:
**Failed restores lose checksums** When New Site from Backup fails during restore, this change leaves no checksum record before the downloaded files are deleted. That makes a bad backup harder to diagnose. Preserve failure-path checksums for this workflow, which Press also uses for [site migrations](https://github.com/frappe/press/blob/HEAD/press/press/doctype/site_migration/site_migration.py).
**Knowledge Base Used:** [Backup and restore](https://app.greptile.com/frappe/-/custom-context/knowledge-base/frappe/agent/-/docs/backup-and-restore.md)
---
For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.Both callers of download_files, restore_job and new_site_from_backup, enter their cleanup block only after the download returns. A failed download left its temporary directory behind, and each retry made a new one, so retries could fill the disk. The read timeout makes a failed download more common, because a stall used to hang instead. The cleanup is in download_files, so it covers both callers. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx
A restore of a 4 GB backup from ap-south-1 to a server in Ashburn ran for 4 hours and then hit the RQ job timeout. Node metrics of the server show almost no inbound bytes during that time, after a short burst of inbound packet loss. The connection had stalled.
download_filecalledrequests.getwith no timeout, and a receiving socket has no timer of its own, so the job waited until RQ killed it.download_filenow usestimeout=(10, 60). If no bytes arrive for 60 s, the step fails and the operator can retry. A slow download that still moves is not affected.pv:Private files: 1.20GB 0:07:10 [2.86MB/s] [=====> ] 71% ETA 0:02:48. Press already sends the output of a running step to the job page whenrealtime_job_updatesis on, so a user can see a stall and cancel the job. The step returns these lines as its output, so they stay on the job page after the step ends. The checksum of the files stays in the Checksum of Downloaded Backup Files step, which runs only when the restore fails. Restore Site and New Site from Backup can already be cancelled from the dashboard.download_filesnow removes its temporary directory. Both callers (restore_jobandnew_site_from_backup) clean up only after a successful download, so each failed retry used to leave its partial files on disk.Tests use a local HTTP server. The stall test fails without the timeout. I also ran it on a local Frappe Cloud with a 200 MB backup served at 1 MB/s. The job page showed the bar live, and a stall made the step fail after 63 s with
Read timed out.🤖 Generated with Claude Code
https://claude.ai/code/session_01QvW4yBq21UUV5GdWUt1HFx