From 4d3ddf502f090a110594aede0554fbc935e2657a Mon Sep 17 00:00:00 2001 From: Cobb Date: Thu, 6 Aug 2026 08:17:15 -0700 Subject: [PATCH] =?UTF-8?q?diag:=20expand=20dogfood=20logging=20=E2=80=94?= =?UTF-8?q?=20lighter=20scrub=20+=20always-log=20failures=20+=20wrapper=20?= =?UTF-8?q?catch-all?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Pairs with strawcore's new extractor instrumentation to make "Send logs to Kayos" actually diagnosable. Today's bot-wall outage produced a log dump that was 90% framework noise, one mangled strawcore line, and zero failure signal. - LogDump: split the scrubber into a FULL profile (share-sheet export + on-screen error strings — unchanged, still over-redacts) and a lighter DOGFOOD profile (the logs.sulkta.com ingest path, our own infra) that KEEPS bare YouTube ids (video/channel/playlist/youtu.be — the triage signal) while still scrubbing every real credential: signed googlevideo URLs, bearer/cookie/token headers, sig/pot/n/cpn params, URL queries, emails, high-entropy tokens (visitorData), and IPs. LogShipper uses the dogfood profile. - Fixed the IPv6-compressed regex that mangled Rust module paths (`strawcore::stream` -> `strawcorstream`) and, as a bonus, a latent false-negative where `::1` was never scrubbed. - Always-log extraction + playback failures (strawLogI) so a user-visible failure always lands in the ring. - Wrapper (rust/strawcore): one catch-all WARN in run_extract that traces EVERY extraction failure system-wide, and raise android_logger Info->Debug so the extractor's DEBUG tier is live in the dogfood build. - Added a JVM unit test for the scrubber (not yet wired into CI — the repo has no test source set; follow-up). --- rust/Cargo.lock | 1 + rust/strawcore/src/lib.rs | 6 +- rust/strawcore/src/runtime.rs | 16 ++- .../feature/detail/VideoDetailViewModel.kt | 13 ++- .../sulkta/straw/feature/diag/LogShipper.kt | 12 +- .../straw/feature/player/ExpandablePlayer.kt | 8 +- .../straw/feature/player/PlayerScreen.kt | 7 +- .../kotlin/com/sulkta/straw/util/LogDump.kt | 83 ++++++++++--- .../com/sulkta/straw/util/LogDumpScrubTest.kt | 110 ++++++++++++++++++ 9 files changed, 225 insertions(+), 31 deletions(-) create mode 100644 strawApp/src/test/kotlin/com/sulkta/straw/util/LogDumpScrubTest.kt diff --git a/rust/Cargo.lock b/rust/Cargo.lock index d86c0e89c..72ffe409e 100644 --- a/rust/Cargo.lock +++ b/rust/Cargo.lock @@ -1571,6 +1571,7 @@ dependencies = [ name = "strawcore-core" version = "0.1.0" dependencies = [ + "log", "once_cell", "parking_lot", "regex", diff --git a/rust/strawcore/src/lib.rs b/rust/strawcore/src/lib.rs index d07fe1d55..48284a17c 100644 --- a/rust/strawcore/src/lib.rs +++ b/rust/strawcore/src/lib.rs @@ -33,7 +33,11 @@ pub fn init_logging() { ONCE.call_once(|| { android_logger::init_once( android_logger::Config::default() - .with_max_level(log::LevelFilter::Info) + // Debug (not Info) so the extractor's DEBUG tier — per-request + // HTTP breadcrumbs, cache/lexer-fallback internals — is live in + // this dogfood/debug build. WARN/INFO were already emitted; this + // unlocks the chatty diagnostics behind them. + .with_max_level(log::LevelFilter::Debug) .with_tag("strawcore"), ); log::info!("strawcore initialized"); diff --git a/rust/strawcore/src/runtime.rs b/rust/strawcore/src/runtime.rs index eb5fc40aa..ff0c7e71c 100644 --- a/rust/strawcore/src/runtime.rs +++ b/rust/strawcore/src/runtime.rs @@ -122,7 +122,10 @@ pub(crate) async fn run_extract(what: &'static str, f: F) -> Result Result + Send + 'static, T: Send + 'static, - E: Send + 'static, + // `Display` so the single catch-all below can log the error. Every caller + // passes a core `ExtractionError`, whose Display is already URL/token + // scrubbed at the source (exceptions.rs choke points), so this is safe. + E: std::fmt::Display + Send + 'static, StrawcoreError: From, { match tokio::time::timeout(EXTRACT_TIMEOUT, tokio::task::spawn_blocking(f)).await { @@ -136,7 +139,14 @@ where msg: format!("join: {join}"), }), // Blocking task returned; propagate its own error via the existing - // `From` mapping. - Ok(Ok(inner)) => inner.map_err(StrawcoreError::from), + // `From` mapping. This is the single catch-all for + // EVERY extraction failure system-wide (incl. the bot-wall) — one WARN + // here means no failure path is silent. Display strings are scrubbed + // at the source, so this never leaks a stream URL or token. + Ok(Ok(Ok(v))) => Ok(v), + Ok(Ok(Err(err))) => { + log::warn!("strawcore::{what} failed: {err}"); + Err(StrawcoreError::from(err)) + } } } diff --git a/strawApp/src/main/kotlin/com/sulkta/straw/feature/detail/VideoDetailViewModel.kt b/strawApp/src/main/kotlin/com/sulkta/straw/feature/detail/VideoDetailViewModel.kt index cb67041c4..336c6e6f9 100644 --- a/strawApp/src/main/kotlin/com/sulkta/straw/feature/detail/VideoDetailViewModel.kt +++ b/strawApp/src/main/kotlin/com/sulkta/straw/feature/detail/VideoDetailViewModel.kt @@ -26,6 +26,7 @@ import com.sulkta.straw.net.SponsorBlockClient import com.sulkta.straw.feature.search.StreamItem import com.sulkta.straw.util.isAllowedYtUrl import com.sulkta.straw.util.runCatchingCancellable +import com.sulkta.straw.util.strawLogI import kotlinx.coroutines.CancellationException import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.Job @@ -330,12 +331,18 @@ class VideoDetailViewModel : ViewModel() { } catch (t: Throwable) { if (t is CancellationException) throw t if (_ui.value.loadedUrl != streamUrl) return@launch + // FULL scrub — this reason is rendered to the UI below (and so + // is screenshot-reachable). The always-log line seeds the + // dogfood ring with the user-visible extraction failure; the + // ring's own (lighter) scrub applies at send time. + val reason = com.sulkta.straw.util.LogDump.scrubLine( + t.message ?: t.javaClass.simpleName, + ) + strawLogI("StrawDetail", "extraction failed: $reason") _ui.update { VideoDetailUiState( loading = false, - error = com.sulkta.straw.util.LogDump.scrubLine( - t.message ?: t.javaClass.simpleName, - ), + error = reason, loadedUrl = streamUrl, ) } diff --git a/strawApp/src/main/kotlin/com/sulkta/straw/feature/diag/LogShipper.kt b/strawApp/src/main/kotlin/com/sulkta/straw/feature/diag/LogShipper.kt index 5de33c408..26ba8fd75 100644 --- a/strawApp/src/main/kotlin/com/sulkta/straw/feature/diag/LogShipper.kt +++ b/strawApp/src/main/kotlin/com/sulkta/straw/feature/diag/LogShipper.kt @@ -13,8 +13,11 @@ * * manual — the Settings → Diagnostics "Send logs to Kayos" button. * * PRIVACY: every line — including the crash stacktrace — goes through - * LogDump.scrubLine before leaving the device; the server re-scrubs, - * but the phone is the primary gate. device_id is a per-install random + * LogDump.scrubLineDogfood before leaving the device (the lighter + * profile for our own logs.sulkta.com: it still redacts every + * credential/URL/token, but keeps bare video/channel/playlist ids as + * outage-triage signal); the server re-scrubs, but the phone is the + * primary gate. device_id is a per-install random * UUID (no ANDROID_ID / IMEI / hardware fingerprint). And the whole * feature only exists in builds where BuildConfig.STRAW_LOGS_TOKEN was * injected (see strawApp/build.gradle.kts) — for everyone else @@ -172,8 +175,11 @@ object LogShipper { throwable.printStackTrace(PrintWriter(it)) }.toString() .split('\n') + // Dogfood profile: this whole shipper targets our own + // logs.sulkta.com, so keep diagnostic ids while still + // scrubbing every credential/URL/token the trace may carry. .take(400) - .map(LogDump::scrubLine) + .map(LogDump::scrubLineDogfood) val ring = LogDump.captureScrubbedLinesBlocking(MAX_LINES) postLines( context = context, diff --git a/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/ExpandablePlayer.kt b/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/ExpandablePlayer.kt index 8e625ae27..a9b518f46 100644 --- a/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/ExpandablePlayer.kt +++ b/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/ExpandablePlayer.kt @@ -105,6 +105,7 @@ import com.sulkta.straw.data.Settings import com.sulkta.straw.feature.detail.VideoDetailBody import com.sulkta.straw.feature.detail.VideoDetailViewModel import com.sulkta.straw.util.LogDump +import com.sulkta.straw.util.strawLogI import kotlinx.coroutines.launch // Snappy, no overshoot. A spring adapts its speed to the remaining @@ -482,7 +483,12 @@ private fun InlinePlayerSurface( val listener = object : Player.Listener { override fun onPlayerError(error: androidx.media3.common.PlaybackException) { val raw = error.message ?: "(no message)" - playbackError = "${error.errorCodeName}: ${LogDump.scrubLine(raw)}" + // FULL scrub — this is rendered in the on-screen error banner. + val scrubbed = "${error.errorCodeName}: ${LogDump.scrubLine(raw)}" + playbackError = scrubbed + // Always-log so the dogfood ring keeps the user-visible + // playback failure (the ring's own scrub applies at send time). + strawLogI("StrawPlayer", "playback error: $scrubbed") NowPlaying.clear() } } diff --git a/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/PlayerScreen.kt b/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/PlayerScreen.kt index d44f7132a..be4724b19 100644 --- a/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/PlayerScreen.kt +++ b/strawApp/src/main/kotlin/com/sulkta/straw/feature/player/PlayerScreen.kt @@ -132,7 +132,12 @@ fun PlayerScreen( // string — visible in the on-screen error banner and // a screenshot away from being shared. val raw = error.message ?: "(no message)" - playbackError = "${error.errorCodeName}: ${LogDump.scrubLine(raw)}" + // FULL scrub — this is rendered in the on-screen error banner. + val scrubbed = "${error.errorCodeName}: ${LogDump.scrubLine(raw)}" + playbackError = scrubbed + // Always-log so the dogfood ring keeps the user-visible + // playback failure (the ring's own scrub applies at send time). + strawLogI("StrawPlayer", "playback error: $scrubbed") // Also clear NowPlaying so the minibar doesn't keep // claiming a dead session is loaded. NowPlaying.clear() diff --git a/strawApp/src/main/kotlin/com/sulkta/straw/util/LogDump.kt b/strawApp/src/main/kotlin/com/sulkta/straw/util/LogDump.kt index ec922c4bd..a34d1ccf4 100644 --- a/strawApp/src/main/kotlin/com/sulkta/straw/util/LogDump.kt +++ b/strawApp/src/main/kotlin/com/sulkta/straw/util/LogDump.kt @@ -122,7 +122,9 @@ object LogDump { } // Scrub only the retained window — cheaper than scrubbing lines // that get dropped, and nothing raw ever leaves this function. - return ring.map(::scrubLine) + // This is the dogfood ingest path (LogShipper → logs.sulkta.com, our + // own infra), so use the lighter profile that keeps diagnostic ids. + return ring.map(::scrubLineDogfood) } /** @@ -132,10 +134,13 @@ object LogDump { * approach catches every documented leak vector at zero * allocation cost. * - * BIAS: over-redaction. These lines leave the device (share sheet - * + LogShipper → logs.sulkta.com), so a false positive costs a - * little debug signal while a false negative leaks what someone - * watched. Anything URL-, token-, id-, or address-shaped goes. + * BIAS: over-redaction. This FULL profile backs the share-sheet + * export and every on-screen error string, which can be handed to a + * chooser app or screenshotted, so a false positive costs a little + * debug signal while a false negative leaks what someone watched. + * Anything URL-, token-, id-, or address-shaped goes. (The dogfood + * ingest path to our own logs.sulkta.com uses the lighter + * [scrubLineDogfood] instead — it keeps bare identifiers.) * * Public so error-handler call sites (PlayerScreen / VideoDetail * `playbackError`) can scrub Media3's `PlaybackException.message` @@ -143,7 +148,30 @@ object LogDump { * request URI for HttpDataSource exceptions, which would otherwise * be a leak via screenshot. */ - fun scrubLine(line: String): String { + fun scrubLine(line: String): String = scrub(line, keepIdentifiers = false) + + /** + * DOGFOOD profile — for the logs.sulkta.com ingest path ONLY (our own + * infra, driven by [LogShipper]). Scrubs every real credential / PII + * vector exactly as [scrubLine] does (googlevideo URLs, bearer tokens, + * cred headers/params, signed params, URL tails, emails, high-entropy + * tokens, IPs), but KEEPS the bare YouTube identifiers — 11-char video + * ids, channel/playlist ids, schemeless youtu.be links — because those + * are the diagnostic signal we triage an outage on, and they only ever + * reach a server we run. NEVER use this for the share-sheet export or a + * string rendered to the UI; those keep the FULL [scrubLine] profile. + */ + fun scrubLineDogfood(line: String): String = scrub(line, keepIdentifiers = true) + + /** + * Shared scrub core. [keepIdentifiers] = true selects the lighter + * DOGFOOD profile: it SKIPS the four identifier replacements (schemeless + * youtu.be, channel id, playlist id, bare video id) so those survive, + * while every credential / high-entropy / IP vector is still redacted in + * BOTH profiles. Step ORDER is unchanged from the original full pass, so + * `keepIdentifiers = false` is byte-for-byte the old behavior. + */ + private fun scrub(line: String, keepIdentifiers: Boolean): String { var s = line // Pre-signed googlevideo URLs: keep the host label visible, drop // host prefix + path + query (session-bound streaming creds). @@ -162,22 +190,29 @@ object LogDump { // /vi// thumbnails, search terms, etc. live. s = URL_TAIL_RE.replace(s, "$1/") // Schemeless YT links pasted into log messages ("youtu.be/xyz"). - s = SCHEMELESS_YT_RE.replace(s, "$1/") + // KEPT on the dogfood profile — the id is diagnostic signal. + if (!keepIdentifiers) { + s = SCHEMELESS_YT_RE.replace(s, "$1/") + } // Emails. s = EMAIL_RE.replace(s, "") - // YouTube channel + playlist ids (watch behavior). - s = CHANNEL_ID_RE.replace(s, "") - s = PLAYLIST_ID_RE.replace(s, "") - // Bare 11-char video-id-shaped tokens ("dQw4w9WgXcQ") logged - // outside any URL (rustypipe/strawcore do this). Requiring a - // digit/_/- inside the run spares ordinary 11-letter words; - // real ids virtually always contain one. Pure-alpha ids are - // still caught earlier when keyed (v=…) or inside a URL. - s = VIDEO_ID_CANDIDATE_RE.replace(s) { m -> - if (m.value.any { it.isDigit() || it == '_' || it == '-' }) "" else m.value + // YouTube channel / playlist / bare video ids (watch behavior). + // KEPT on the dogfood profile — the signal we triage outages on. + if (!keepIdentifiers) { + s = CHANNEL_ID_RE.replace(s, "") + s = PLAYLIST_ID_RE.replace(s, "") + // Bare 11-char video-id-shaped tokens ("dQw4w9WgXcQ") logged + // outside any URL (rustypipe/strawcore do this). Requiring a + // digit/_/- inside the run spares ordinary 11-letter words; + // real ids virtually always contain one. Pure-alpha ids are + // still caught earlier when keyed (v=…) or inside a URL. + s = VIDEO_ID_CANDIDATE_RE.replace(s) { m -> + if (m.value.any { it.isDigit() || it == '_' || it == '-' }) "" else m.value + } } // Long high-entropy runs (hashes, visitor data, unlabeled - // tokens): 20+ [A-Za-z0-9_-] chars containing a digit. + // tokens): 20+ [A-Za-z0-9_-] chars containing a digit. Scrubbed + // in BOTH profiles — visitorData & friends are creds, not signal. s = LONG_TOKEN_RE.replace(s, "") // IP addresses (v4 + v6 — v6 patterns are shaped so threadtime // HH:MM:SS timestamps can never match). @@ -250,7 +285,17 @@ object LogDump { private val IPV6_FULL_RE = Regex( """(?=1 hex group). That kills + // the old false positive where a Rust module path — a lone hex letter + `::` + // + a non-hex word, e.g. `strawcore::stream` — got scrubbed to + // `strawcorstream`. The trailing lookahead rejects a following word char + // so `stream::foo` (foo starts with hex `f`) can't clip `::f` either. Real + // compressed IPv6 (`::1`, `fe80::1`, `2001:db8::1`) still scrubs; a bare + // `fe80::`-with-nothing-after is intentionally let through (rare in logs, + // and cheaper than re-opening the false-positive hole). private val IPV6_COMPRESSED_RE = Regex( - """(?stream` + // because `e::` read as a compressed IPv6. It must now pass through + // untouched in BOTH profiles. + assertEquals("strawcore::stream", LogDump.scrubLine("strawcore::stream")) + assertEquals("strawcore::stream", LogDump.scrubLineDogfood("strawcore::stream")) + // A three-segment path — `::foo` must not clip `::f` (foo starts with + // the hex letter `f`). + assertEquals("strawcore::stream::foo", LogDump.scrubLine("strawcore::stream::foo")) + // Embedded in a realistic log line. + val line = "W strawcore: extracting strawcore::stream::foo failed" + assertEquals(line, LogDump.scrubLine(line)) + } + + @Test + fun realCompressedIpv6StillScrubs() { + // Loopback `::1` (a leading `::` — the OLD regex actually missed this), + // link-local, and documentation-range compressed forms all redact. + assertEquals("", LogDump.scrubLine("::1")) + assertEquals("", LogDump.scrubLine("fe80::1")) + assertEquals("", LogDump.scrubLine("2001:db8::1")) + assertEquals("", LogDump.scrubLine("2604:2dc0::1")) + // In-context, too. + assertTrue(LogDump.scrubLine("bound peer fe80::1 up").contains("")) + assertFalse(LogDump.scrubLine("bound peer fe80::1 up").contains("fe80")) + } + + // ---- B2: dogfood profile KEEPS diagnostic identifiers ---------------- + + @Test + fun dogfoodKeepsBareVideoIdFullScrubs() { + val id = "dQw4w9WgXcQ" + assertEquals(id, LogDump.scrubLineDogfood(id)) + assertEquals("", LogDump.scrubLine(id)) + } + + @Test + fun dogfoodKeepsYoutubeShortLinkFullScrubs() { + val line = "open youtu.be/dQw4w9WgXcQ now" + // Dogfood: the youtu.be/ stays — the id is the diagnostic signal. + assertEquals(line, LogDump.scrubLineDogfood(line)) + // Full: the schemeless YT link is redacted. + assertTrue(LogDump.scrubLine(line).contains("")) + assertFalse(LogDump.scrubLine(line).contains("dQw4w9WgXcQ")) + } + + // ---- B2: dogfood profile STILL scrubs real credentials / PII --------- + + @Test + fun dogfoodStillScrubsSignedGooglevideoUrl() { + val line = + "url=https://r5---sn-abc.googlevideo.com/videoplayback?expire=99&sig=DEADBEEFSIG&pot=SECRETPOT" + val out = LogDump.scrubLineDogfood(line) + assertTrue(out.contains("")) + assertFalse(out.contains("DEADBEEFSIG")) + assertFalse(out.contains("SECRETPOT")) + } + + @Test + fun dogfoodStillScrubsBearerToken() { + val out = LogDump.scrubLineDogfood("hdr Authorization: Bearer ya29.A0ARLongTokenValue123") + assertTrue(out.contains("")) + assertFalse(out.contains("ya29")) + } + + @Test + fun dogfoodStillScrubsSignedParams() { + val out = LogDump.scrubLineDogfood("req q&sig=DEADBEEF123&pot=POTVAL456 done") + assertTrue(out.contains("sig=")) + assertTrue(out.contains("pot=")) + assertFalse(out.contains("DEADBEEF123")) + assertFalse(out.contains("POTVAL456")) + } + + @Test + fun dogfoodStillScrubsIpAddresses() { + val out = LogDump.scrubLineDogfood("peer 203.0.113.7 and fe80::1 up") + assertTrue(out.contains("")) + assertFalse(out.contains("203.0.113.7")) + assertFalse(out.contains("fe80")) + } +}