Keep the Mac awake while downloading, and stop the log and ETA from lying - #9
Conversation
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
|
Correcting the sleep-assertion claim in this PR's description before anyone relies on it. The assertion is held, but it does not fix the stalls it was written for. I measured again, this time reading the reason column: Every entry after each of those is Second problem, independent of the first: this host has I am leaving the code in rather than reverting. It is correct, costs one assertion re-evaluated on an existing 2-second poll, releases properly — verified from What actually helps on this machine: keep the lid open while downloading, or Worth building, but a separate decision: the app can detect this state (it holds an assertion, yet monotonic time has not advanced) and tell the user that the download stalled because the Mac slept, rather than leaving them to conclude the engine is broken. |
Every dependency with an available update moves to its newest release, so the packaged app ships the current Phoenix/LiveView security and bug fixes instead of trailing them. dns_cluster needed its requirement widened to ~> 0.3.0; the 0.3.0 API is compatible with our single call site, which passes :ignore in every configuration but a DNS_CLUSTER_QUERY deployment. Co-authored-by: Cursor <cursoragent@cursor.com>
daisyUI's `.alert` is a column grid, so the message track cannot shrink below its min-content width. Torrent names are usually one long token without spaces, which made min-content wider than the fixed toast and pushed the text out past the right edge instead of wrapping. `text-wrap` alone cannot help, because there are no word boundaries to break on. `wrap-anywhere` lets the text break mid-token, which also collapses min-content so the grid track fits inside the toast. Co-authored-by: Cursor <cursoragent@cursor.com>
…ever `openServerLog` appended with `seekToEndOfFile` and never rotated, so the file grew unbounded for the life of the install. A diagnostic build made it acute at roughly 72 KB/s; a 73 MB log was found in place. Rotation happens **at launch only**, and that is the load-bearing detail: the running release holds the descriptor, so renaming the file out from under it leaves the live file empty while the app keeps writing to an unlinked inode. One generation (`server.log.1`) at a 20 MiB threshold is enough to keep the previous session's tail for diagnosis. Co-authored-by: Cursor <cursoragent@cursor.com>
The macOS launcher polls `GET /api/torrents` every two seconds to keep the Dock menu current. Demoting those two lines per poll to `:debug` was not enough: a release purges `:debug` at compile time, but a diagnostic build does not, and the poll then dominates the capture and hides real signal at 43 200 requests a day. `Plug.Telemetry` accepts `false` as a level, which suppresses the pair outright. Only the poll is silenced — `POST /api/torrents` adds a torrent and everything else keeps `:info`. Co-authored-by: Cursor <cursoragent@cursor.com>
`config :logger, compile_time_purge_matching: [[level_lower_than: :info]]` removes every `Logger.debug` call site from the release, which is right for a shipped app and makes the packaged build impossible to diagnose: raising the level over RPC finds nothing left to enable. `ELIXIR_TORRENT_DEBUG_BUILD=1 mix mac.dmg` now keeps the call sites, so the level can be moved at runtime without a rebuild. The default path is unchanged. Co-authored-by: Cursor <cursoragent@cursor.com>
The app took no power assertion, so macOS idle-slept the Mac underneath an active
transfer. Measured overnight: 64 minutes awake in a 7-hour window, with the engine
suspended for the rest. This is invisible from inside the BEAM because
`:erlang.statistics(:wall_clock)` counts awake time only — monotonic time does not
advance across system sleep, so uptime, timers and rate windows all look normal
while nothing is on the wire. It reads as a swarm problem: peers time out en
masse on resume because the TCP connections died while we were not running.
`SleepPreventer` takes `kIOPMAssertPreventUserIdleSystemSleep` while any torrent
is `Downloading` and releases it otherwise, driven off the Dock refresh loop that
already polls every two seconds — no new timer, and the assertion follows the same
state the Dock menu shows. It is released explicitly in
`applicationShouldTerminate` rather than relying on process exit.
Two deliberate choices:
* The assertion is taken **only on AC power**. A download is not worth draining
a battery the user is not watching, and `IOPSGetProvidingPowerSourceType`
answers this cheaply. A machine with an unreadable power source is treated as
AC, since a desktop is the common case there.
* The gate is `status == "Downloading"`, not `downKbps > 0`. The speed readout is
piece-granular and reads 0 during normal operation (engine `PLAN.md` #53b), so
gating on it would drop the assertion between pieces — the exact moments the
transfer needs to stay alive.
This is a display-sleep-permitting assertion: the screen still sleeps, only the
system stays awake, which is what a background transfer needs.
`IOKit` is now linked in both the packaging script and the launcher integration
test, which compiles the same sources.
Co-authored-by: Cursor <cursoragent@cursor.com>
Reported from the UI on a torrent showing a remaining time of order 1e39 days. `compute_eta/4` returns `left / (kbps * 1024)` with no upper bound and `format_eta/1` prints a concrete figure for whatever it gets, so any near-zero but non-zero rate produces a number that reads as a corrupted value rather than an estimate. The rate in question had decayed to ~1e-39 KB/s; that source is fixed separately in the engine, but the formatter should not depend on the rate being sane. Anything past 100 days is now `:infinity`, which already renders as `∞`. qBittorrent caps its own ETA at the same horizon for the same reason. A genuinely slow estimate — 12 hours on 462 MB at 10 KB/s — still reports a real number, because that is actionable and the cap must not swallow it. Co-authored-by: Cursor <cursoragent@cursor.com>
The gate was `status == "Downloading"`, which is narrower than the intent. The engine derives that status from the piece currently being fetched (`Peer.status()` is `nil | :seed | :connecting_to_peers | index`), so an **incomplete** torrent reports `"Idle"` or `"Connecting"` whenever no piece is assigned to it. Behind CGNAT, where a torrent runs on one to three peers, that is a state it passes through constantly while hunting for somewhere to ask — and letting the Mac sleep there strands it exactly when re-dialling is the only thing that can rescue it, because sleep drops every peer connection it might have been about to establish. `!= "Seeding"` is the same test the Dock menu already applies when it files torrents under its "Downloading:" heading, so the assertion and the menu now agree on what counts as active. There is no paused or stopped status to worry about letting through: `Peer.status()` has no such value, and a stopped torrent is not in the list at all. Found by reading `powerd`'s own log after deploying the original commit — `log show --predicate 'eventMessage CONTAINS "ElixirTorrentWebUI"'` shows every acquire and release with an age, which is a better instrument for this than `pmset -g assertions` because it shows the transitions rather than the current state. It recorded a release-and-reacquire on a torrent that never stopped being incomplete. Forty consecutive two-second samples afterwards all read `"Downloading"`, so this specific flap is not reproduced on demand — but the code path is plainly there, and the conservative gate has no upside on AC power. Co-authored-by: Cursor <cursoragent@cursor.com>
cfb1d70 to
6405bb2
Compare
Five changes to the packaged macOS app. The headline one is that the app never asked macOS to stay awake, so unattended downloads barely progressed; the rest are the log hygiene and display bugs found while diagnosing it.
The Mac was asleep, and nothing inside the BEAM could see it
An overnight run read like an engine disaster: throughput down from 1.7 MB/s to ~1.6 KB/s (19 MB in 3¼ hours), one torrent frozen for two hours, and an apparent uptime of 64 minutes on a build deployed 7 hours earlier — which looked like two silent restarts.
None of it was an engine fault.
server.logwas continuous with no restart marker, and:erlang.statistics(:wall_clock)is derived from monotonic time, which on macOS does not advance across system sleep. It reports awake time, not uptime.pmset -g logshowed the Mac in repeated'Maintenance Sleep':TCPKeepAlive=activeall night, waking only for 45-second DarkWake slices, one sleep stretch lasting 88 minutes: 64 minutes of awake time in 7 hours. Thereason=:etimedoutpeer-dial burst after each wake is the expected consequence, since sleep kills every peer TCP connection and each wake has to re-dial the swarm from cold.grep -rn 'caffeinate\|IOPMAssertion\|beginActivity\|NSProcessInfo'over the Swift and Elixir sources returned nothing: no power assertion had ever been taken. The only onepmsetattributed to the app was an incidental 1-second CFNetwork assertion created byrunningboardd.SleepPreventer.swiftnow holdskIOPMAssertPreventUserIdleSystemSleep, driven off the existing 2-second Dock refresh poll rather than a timer of its own, and released explicitly inapplicationShouldTerminate. It permits display sleep — only the system stays awake, which is what a background transfer needs.Three deliberate choices:
IOPSGetProvidingPowerSourceTypeanswers this cheaply. A machine with an unreadable power source is treated as AC, since a desktop is the common case there.status == "Downloading", notdownKbps > 0. The speed readout is piece-granular and reads0.0during normal operation, so gating on it would drop the assertion between pieces — exactly the moments the transfer needs the machine awake.The remaining time displayed a number of order 1e39 days
Reported from the UI.
compute_eta/4returnsleft / (kbps * 1024)with no upper bound andformat_eta/1prints a concrete figure for whatever it gets, so any near-zero-but-non-zero rate produces a value that reads as corrupted rather than as an estimate. The rate in question had decayed to about1e-39KB/s.The rate is fixed on the engine side, but the formatter should not depend on the rate being sane: anything past 100 days is now
:infinity, which already renders as the infinity sign. qBittorrent caps its own ETA at the same horizon for the same reason. A genuinely slow estimate — 12 hours on 462 MB at 10 KB/s — still reports a real number, because that is actionable and the cap must not swallow it.Log hygiene
server.logis rotated at launch.openServerLogappended withseekToEndOfFileand never rotated, so the file grew unbounded for the life of the install; a diagnostic build made it acute at roughly 72 KB/s and a 73 MB log was found in place. Rotation happens at launch only, and that is the load-bearing detail: the running release holds the descriptor, so renaming the file out from under it leaves the live file empty while the app keeps writing to an unlinked inode. One generation at a 20 MiB threshold.The launcher's Dock poll is no longer logged at all. It hits
GET /api/torrentsevery two seconds. Demoting the pair of lines to:debugwas not enough, because a diagnostic build does not purge:debugand the poll then dominates the capture at 43 200 requests a day.Plug.Telemetryacceptsfalseas a level. Only the poll is silenced;POST /api/torrentsand everything else keep:info.An opt-in diagnostic build keeps the debug call sites.
compile_time_purge_matchingremoves everyLogger.debugcall site from the release, which is right for a shipped app and makes the packaged build impossible to diagnose — raising the level over RPC finds nothing left to enable.ELIXIR_TORRENT_DEBUG_BUILD=1 mix mac.dmgkeeps them. The default path is unchanged.Verification
Every gate of
web-build-test-analyze.ymland the checkable gates ofbuild-macos.ymlwere run locally, in CI's order, before pushing. All green:mix testmix test --only macos_integrationpriv/macos/src/*.swiftfor real, so it covers the newIOKitlinkswiftlint lint --strictmix dialyzermix credo --allmix sobelow --skip --strict --private --exit --threshold mediummix format --check-formattedmix compile --warnings-as-errors(dev + test)mix hex.audit,mix deps.unlock --check-unusedmix mac.dmgDeployed and verified live on the packaged app:
pmset -g assertionsshowspid 92513(ElixirTorrentWebUI): PreventUserIdleSystemSleep named: "ElixirTorrent is downloading"held by our own process, distinct from the incidentalrunningboarddone. ETAs read 1h 37m and 7h 10m on the two downloading torrents instead of an astronomical figure.Validated by inspection only, not live: the release-on-battery and release-when-all-complete paths of the assertion, since both need a hardware or queue state change to exercise.
Not reproducible locally:
build-windows.yml, and the Codecov upload.Note that
mix.lockwas reconciled during the rebase: two Dependabot merges onmainlanded older versions than this branch already carried (phoenix 1.8.12 against 1.8.13, phoenix_live_view 1.2.10 against 1.2.11, phoenix_pubsub 2.2.0 against 2.3.0). The newer set was kept and re-validated withmix deps.get --check-locked; bandit was 1.12.5 on both sides, so nothing was downgraded.