Skip to content

Commit a67a240

Browse files
fix: keep the streaming OAuth callback alive through browser noise (#423)
# Summary Fixes #414. The streaming login hands port 8989 to librespot, whose callback server accepted exactly one connection and gave up if it was not the redirect, dropping the listener and closing the port. Some browsers, LibreWolf in particular, send a bare CRLF or open a connection without writing to it before the real callback arrives. librespot consumed that, failed to parse it, and closed the port, so the redirect carrying the code hit a dead port. The user is left on a browser "unable to connect" page, and because the flow errors before `save_credentials` it repeats on every launch, which is the "streaming cookie does not get cached" the reporter described. Not Windows specific. Three independent reports line up: upstream [librespot#1705](librespot-org/librespot#1705) (LibreWolf + ncspot on Fedora, with a debug trace showing the empty line and vanilla Firefox working as a control), #234 (LibreWolf on Gentoo, same "web API login works, streaming fails" split), and #364 (a commenter with `AuthCodeListenerParse` in their log who confirmed Chrome works). The common variable is the browser. spotatui's own callback server never had this problem: `extract_callback_url` runs `split_whitespace()` over the whole buffer, which steps over a leading CRLF, and it answers unrelated requests with a 400 and keeps waiting. `read_line` stops at the first `\n`. Only the librespot half was fragile, which is why the web API login succeeded and the streaming one did not. Fixed in our librespot fork rather than here, since that is where the defective listener lives. The fork cherry-picks upstream PR [#1706](librespot-org/librespot#1706) with its original attribution, then hardens it: #1706 skips to the next *connection* on a blank line, which is correct only if the blank line arrives on its own connection and hangs if it is a leading CRLF on the same one. This PR bumps the `[patch.crates-io]` rev to pick that up. Three unrelated startup bugs found while tracing this are fixed in their own commits: - **Auto-update deadlock.** `run_auto_update` ran concurrently with authentication in a `tokio::join!` and re-exec'd immediately on a successful install. The re-exec blocks the task in `Command::status()`, so the joined authentication future stops being polled while it still owns the callback port, and the child, which repeats startup from scratch, cannot bind that port. The parent waits on the child, the child waits on a port the parent will never release. The check still runs concurrently; only the restart moves to after the join. - **Log path.** `setup_logging` hard-coded `/tmp/spotatui_logs/`, which on Windows is drive-relative, so the app printed a location the user's shell could not resolve directly above the line inviting them to report bugs. Now resolved through `std::env::temp_dir`. - **OAuth port probe.** `wait_for_oauth_callback_port` refused to start the login when its probe timed out, so we never even attempted and reported something vaguer than the bind error librespot would have produced. It now warns and proceeds. # Testing - `cargo fmt --all` (and `--check`, clean) - `cargo clippy --no-default-features --features telemetry -- -D warnings` (clean) - `cargo clippy -- -D warnings` (clean, default features) - `cargo test --no-default-features --features telemetry` (544 passed) - `cargo test` (809 passed) In the fork, `cargo test -p librespot-oauth` (14 passed) and `cargo clippy -p librespot-oauth --all-targets -- -D warnings` (clean). The listener tests cover both shapes of librespot#1705 (blank line on the same connection, and on a separate one), a `/favicon.ico` request before the callback, a code surviving a browser that hangs up before the success page is written, and a peer dribbling bytes being cut off at the deadline. They run behind a watchdog so a regression fails the suite instead of hanging it. Reviewed across five rounds with the Codex CLI, which caught four real defects: a captured authorization code being discarded when the success page failed to write, the accept loop having no overall deadline, HTTP header lines being read as if each were a request, and the deadline not covering an in-flight read. # Additional notes Not verified against a live LibreWolf on Windows. I am on Linux and cannot reproduce the reporter's setup, so this rests on code reading plus the three corroborating reports above rather than an observed repro. A fork fix reaches everyone who installs today: GitHub releases, winget, Homebrew, both AUR packages, and `install.sh`/`install.ps1` all build with `[patch]` active. The one gap is `cargo install spotatui` from crates.io, which is stuck at 0.40.2 because the v0.40.3 publish job fails to compile against upstream librespot (`unresolved import librespot_connect::SavedPlaybackState`). Worth fixing separately; those users cannot get 0.40.3+ by any route today. Workaround for anyone hitting this before the next release: set `enable_streaming: false` in `client.yml`. That stops the every-launch browser flow and leaves Spotify Connect working. <!-- This is an auto-generated comment: release notes by coderabbit.ai --> ## Summary by CodeRabbit - **New Features** - Log files now use a platform-appropriate temporary directory and include the process ID. - The changelog displays the actual log-file location. - Automatic updates restart after authentication resources are released. - **Bug Fixes** - Improved OAuth callback handling when the callback port is unavailable. - Streaming authentication errors now include more actionable details. - Updated playback and connection reliability fixes. - **Documentation** - Updated safe-by-default guidance to explain how to find the log-file location. <!-- end of auto-generated comment: release notes by coderabbit.ai -->
2 parents e4ef8c2 + 5b7f474 commit a67a240

9 files changed

Lines changed: 182 additions & 77 deletions

File tree

Cargo.lock

Lines changed: 7 additions & 7 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

Cargo.toml

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -226,16 +226,19 @@ pkg-fmt = "zip"
226226
# Native streaming fixes: librespot 0.8.0 + backport of upstream PR #1722 (fall back to the
227227
# next CDN URL when one returns a non-206 status, e.g. HTTP 530) + port of upstream PR #1692
228228
# (dealer reconnects handled in place without restarting spirc; prompt spirc-task exit with
229-
# saved playback state on session TCP loss instead of hanging, enabling seamless recovery).
229+
# saved playback state on session TCP loss instead of hanging, enabling seamless recovery)
230+
# + cherry-pick of upstream PR #1706 and follow-up hardening of the OAuth callback listener,
231+
# which used to accept one connection and give up if it was not the redirect, closing port
232+
# 8989 before the real callback arrived (issue #414, upstream issue #1705).
230233
# Pinned to our maintained fork (spotatui-librespot) until a fixed librespot is published to
231234
# crates.io. Pinned by immutable `rev` (not a branch) so release builds stay reproducible even
232235
# as the `spotatui` branch advances. Note: crates.io publishes ignore [patch], so `cargo install`
233236
# users need the upstream release.
234237
[patch.crates-io]
235-
librespot-core = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
236-
librespot-audio = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
237-
librespot-playback = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
238-
librespot-connect = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
239-
librespot-oauth = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
240-
librespot-metadata = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
241-
librespot-protocol = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "4e9e5c72f079ffe79743ba5245b894c0ab20ce5a" }
238+
librespot-core = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
239+
librespot-audio = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
240+
librespot-playback = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
241+
librespot-connect = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
242+
librespot-oauth = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
243+
librespot-metadata = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }
244+
librespot-protocol = { git = "https://github.com/LargeModGames/spotatui-librespot", rev = "514061e4df71f5827105611eab1b2b92a87c430a" }

docs/configuration.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ Machine-managed runtime state lives separately in `$XDG_STATE_HOME/spotatui/stat
1515

1616
## Safe by default
1717

18-
A typo in `config.yml` never prevents the app from starting. Structural mistakes an unknown sort field, a bad template placeholder, an invalid column id, an icon that is too wideare logged as warnings and the affected value falls back to its built-in default. Warnings go to the log file whose path is printed at startup (`/tmp/spotatui_logs/spotatuilog<pid>`).
18+
A typo in `config.yml` never prevents the app from starting. Structural mistakes (an unknown sort field, a bad template placeholder, an invalid column id, an icon that is too wide) are logged as warnings and the affected value falls back to its built-in default. Warnings go to the log file whose path is printed at startup, a `spotatui_logs/spotatuilog<pid>` file inside your system temp directory (`%TEMP%` on Windows, `$TMPDIR` where set, otherwise `/tmp`). The startup line reports the resolved path, so copy it from there rather than guessing.
1919

2020
Only two kinds of errors are fatal: YAML syntax errors (the file cannot be parsed at all) and a handful of out-of-range numeric values that bypass the warn-and-fallback policy: `volume_increment` outside 0–100, a tick rate (or animation tick rate) outside 1–999ms, an unparseable `auto_update_delay`, `playback_poll_seconds` below 1, and `like_animation_frames` below 1.
2121

flake.nix

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,9 @@
4040
pkgs.apple-sdk
4141
pkgs.portaudio
4242
];
43-
librespotOutputHash = "sha256-F1pAhVgxYsbmLXOcbOEU6mGYZO1n94EWCXn5yjhPxv0=";
43+
# Update alongside the [patch.crates-io] rev in Cargo.toml; the Nix build
44+
# fails with a hash mismatch that reports the correct value otherwise.
45+
librespotOutputHash = "sha256-N/ImWrtEyhKyjvZd8zVCelKtsAV1kHoFHMwCoe5ddI0=";
4446
in
4547
{
4648
# Build dependencies for rust

src/core/app.rs

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1884,6 +1884,9 @@ pub struct App {
18841884
pub plugin_popup: Option<crate::core::plugin_api::PluginPopup>,
18851885
/// Scroll offset for the plugin popup.
18861886
pub plugin_popup_scroll: u16,
1887+
/// Where this run's log file is being written, resolved once here so draw
1888+
/// code can show it without doing the environment lookup every frame.
1889+
pub log_path: String,
18871890
}
18881891

18891892
#[derive(Clone, Copy, PartialEq, Debug)]
@@ -2176,6 +2179,7 @@ impl Default for App {
21762179
plugin_playbar_segments: std::collections::BTreeMap::new(),
21772180
plugin_popup: None,
21782181
plugin_popup_scroll: 0,
2182+
log_path: crate::core::paths::app_log_path().display().to_string(),
21792183
}
21802184
}
21812185
}

src/core/paths.rs

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,25 @@ pub(crate) fn app_state_dir() -> Option<PathBuf> {
5151
)
5252
}
5353

54+
/// Directory holding this run's log file.
55+
///
56+
/// The OS temp directory rather than the state dir: a log file is written per
57+
/// process id, so they accumulate, and temp is the one location the platform
58+
/// clears on its own. Resolved through `std::env::temp_dir` so Windows lands in
59+
/// `%TEMP%` instead of the literal `/tmp` this used to hard-code, which is
60+
/// drive-relative there and left Windows users looking for a path the app
61+
/// reported but their shell could not find.
62+
pub(crate) fn app_log_dir() -> PathBuf {
63+
std::env::temp_dir().join("spotatui_logs")
64+
}
65+
66+
/// Path of this process's log file. Callers on both the writing side
67+
/// (`setup_logging`) and the reporting side (the help screen) use this so the
68+
/// path shown to a user is always the path actually written.
69+
pub(crate) fn app_log_path() -> PathBuf {
70+
app_log_dir().join(format!("spotatuilog{}", std::process::id()))
71+
}
72+
5473
/// Ensure a directory that stores credentials or other private app data exists
5574
/// and is owner-only where supported.
5675
pub(crate) fn ensure_private_dir(dir: &Path) -> Result<()> {

src/infra/player/streaming.rs

Lines changed: 41 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -520,26 +520,27 @@ const SPOTIFY_PLAYER_CLIENT_ID: &str = "65b708073fc0480ea92a077233ca87bd";
520520
/// spotify-player's redirect_uri - must match what's registered with their client_id
521521
const SPOTIFY_PLAYER_REDIRECT_URI: &str = "http://127.0.0.1:8989/login";
522522

523-
fn wait_for_oauth_callback_port(
524-
address: &str,
525-
max_wait: Duration,
526-
retry_delay: Duration,
527-
) -> Result<()> {
523+
/// Wait until `address` looks bindable, so the streaming consent is not opened
524+
/// while the Web API callback server still holds the port.
525+
///
526+
/// Advisory only, and deliberately so. librespot binds the port itself, so the
527+
/// most this can do is probe and release; between that release and librespot's
528+
/// own bind the port is unowned, which no amount of retrying can close. Returns
529+
/// whether the port came free rather than `Result`, because the caller must not
530+
/// treat "still busy" as fatal: librespot's bind is the authority and reports a
531+
/// far better error than this probe can.
532+
fn wait_for_oauth_callback_port(address: &str, max_wait: Duration, retry_delay: Duration) -> bool {
528533
let deadline = Instant::now() + max_wait;
529534
loop {
530535
match std::net::TcpListener::bind(address) {
531536
Ok(listener) => {
532537
drop(listener);
533-
return Ok(());
538+
return true;
534539
}
535540
Err(_) if Instant::now() < deadline => {
536541
std::thread::sleep(retry_delay.min(deadline.saturating_duration_since(Instant::now())));
537542
}
538-
Err(error) => {
539-
return Err(anyhow!(
540-
"OAuth callback port {address} did not become available: {error}"
541-
));
542-
}
543+
Err(_) => return false,
543544
}
544545
}
545546
}
@@ -548,11 +549,15 @@ fn request_streaming_oauth_credentials() -> Result<Credentials> {
548549
// The Web API and streaming OAuth clients both use port 8989. On a fresh
549550
// profile their callback servers run back-to-back, so wait for the first
550551
// listener to be fully released before librespot opens the second consent.
551-
wait_for_oauth_callback_port(
552+
// Advisory: if it is still busy we go ahead anyway and let librespot's own
553+
// bind produce the real error, rather than refusing to try at all.
554+
if !wait_for_oauth_callback_port(
552555
"127.0.0.1:8989",
553556
Duration::from_secs(5),
554557
Duration::from_millis(50),
555-
)?;
558+
) {
559+
warn!("OAuth callback port 127.0.0.1:8989 still busy; attempting the streaming login anyway");
560+
}
556561

557562
let client_builder = OAuthClientBuilder::new(
558563
SPOTIFY_PLAYER_CLIENT_ID,
@@ -1412,13 +1417,34 @@ mod tests {
14121417
drop(listener);
14131418
});
14141419

1415-
wait_for_oauth_callback_port(&address, Duration::from_secs(1), Duration::from_millis(10))
1416-
.expect("callback port should become available after the first listener exits");
1420+
assert!(
1421+
wait_for_oauth_callback_port(&address, Duration::from_secs(1), Duration::from_millis(10)),
1422+
"callback port should become available after the first listener exits"
1423+
);
14171424
release.join().unwrap();
14181425

14191426
std::net::TcpListener::bind(address).expect("callback port should remain available");
14201427
}
14211428

1429+
/// A port that never frees is reported, not fatal: the caller logs and lets
1430+
/// librespot's own bind produce the authoritative error.
1431+
#[test]
1432+
fn oauth_callback_port_reports_a_port_that_stays_busy() {
1433+
let listener = std::net::TcpListener::bind("127.0.0.1:0").unwrap();
1434+
let address = listener.local_addr().unwrap().to_string();
1435+
1436+
assert!(
1437+
!wait_for_oauth_callback_port(
1438+
&address,
1439+
Duration::from_millis(50),
1440+
Duration::from_millis(10)
1441+
),
1442+
"a port held for the whole wait should report as unavailable"
1443+
);
1444+
1445+
drop(listener);
1446+
}
1447+
14221448
#[test]
14231449
fn auth_failure_with_cached_creds_triggers_retry() {
14241450
assert!(should_retry_with_fresh_credentials(true, true, false));

0 commit comments

Comments
 (0)