youtube: instrument the extractor with diagnostic logging
Some checks failed
gitleaks / scan (push) Failing after 4s

The crate had zero logging — every failure, fallback, cache reset, and
empty-parse was silent by construction, which made the 2026 bot-wall outage
nearly undiagnosable. Add `log = "0.4"` and 52 statements across the extractor
following a one-INFO-per-outcome / WARN-on-every-failure / DEBUG-for-internals
policy, so a future break shows up in a log grep instead of a debugger.

Highlights: nsig->throttled-URL fallback (aggregated one WARN per extraction,
never per-format, via a threaded UrlProcessStats counter); the nsig
identity-output trap now returns DeobfError::NsigIdentity and is NOT cached
(previously it cached and permanently throttled); player.js build/eval/install/
StillBad lifecycle; the ANDROID->VISIONOS cascade outcome; visitorData decline +
reset; HTTP 429 bot-flag; channel/search layout-change empties; per-request
DEBUG (query stripped). Plus a `BotDetected` error variant (Display byte-
identical to the old string) so the wall is greppable.

No secrets: only videoId/channel ids, error Displays (already URL/token-scrubbed
at the exceptions.rs choke points), query-stripped endpoints/player.js URLs,
counts, and lengths are logged — never token/poToken/visitorData/signature
values or response bodies.
This commit is contained in:
Cobb 2026-08-06 08:16:42 -07:00
parent dd964407cc
commit 6df61c1f52
14 changed files with 559 additions and 70 deletions

1
Cargo.lock generated
View file

@ -988,6 +988,7 @@ checksum = "6ce2be8dc25455e1f91df71bfa12ad37d7af1092ae736f3a6cd0e37bc7810596"
name = "strawcore-core"
version = "0.1.0"
dependencies = [
"log",
"once_cell",
"parking_lot",
"regex",

View file

@ -19,6 +19,7 @@ reqwest = { version = "0.12", default-features = false, features = ["rustls-tls-
serde = { version = "1", features = ["derive"] }
serde_json = "1"
thiserror = "1"
log = "0.4"
parking_lot = "0.12"
url = "2"
once_cell = "1"

View file

@ -9,7 +9,7 @@
// as Ok(Response)
use std::io::Read;
use std::time::Duration;
use std::time::{Duration, Instant};
use reqwest::blocking::Client;
use reqwest::redirect::Policy;
@ -52,6 +52,11 @@ impl ReqwestDownloader {
impl Downloader for ReqwestDownloader {
fn execute(&self, request: Request) -> Result<Response, NetworkError> {
let started = Instant::now();
let method_str = match request.method() {
Method::Get => "GET",
Method::Post => "POST",
};
let method = match request.method() {
Method::Get => reqwest::Method::GET,
Method::Post => reqwest::Method::POST,
@ -79,6 +84,12 @@ impl Downloader for ReqwestDownloader {
let status = resp.status();
let url_after_redirects = resp.url().to_string();
// Query/fragment carry n/sig/pot/cpn/id — strip for every log line.
let endpoint = url_after_redirects
.split(['?', '#'])
.next()
.unwrap_or(&url_after_redirects)
.to_string();
if status.as_u16() == 429 {
// Privacy: this URL ends up in error strings (and from there in
@ -91,6 +102,8 @@ impl Downloader for ReqwestDownloader {
stripped.set_query(None);
stripped.set_fragment(None);
stripped.set_path("/");
// Densest bot-flag signal — host only (path/query already stripped).
log::warn!("HTTP 429 reCAPTCHA / bot-wall from {stripped} — YouTube is rate-limiting");
return Err(NetworkError::Recaptcha { url: stripped.to_string() });
}
@ -107,6 +120,9 @@ impl Downloader for ReqwestDownloader {
// Fail fast when a known Content-Length already exceeds the cap.
if let Some(len) = resp.content_length() {
if len > MAX_BODY_BYTES {
log::warn!(
"{endpoint}: Content-Length {len}B exceeds cap {MAX_BODY_BYTES}B; aborting"
);
return Err(NetworkError::Transport(format!(
"response body {len} bytes exceeds cap {MAX_BODY_BYTES}"
)));
@ -123,6 +139,7 @@ impl Downloader for ReqwestDownloader {
.read_to_end(&mut buf)
.map_err(|e| NetworkError::Transport(format!("body read: {e}")))?;
if buf.len() as u64 > MAX_BODY_BYTES {
log::warn!("{endpoint}: streamed body exceeded cap {MAX_BODY_BYTES}B; aborting");
return Err(NetworkError::Transport(format!(
"response body exceeded cap {MAX_BODY_BYTES}"
)));
@ -131,11 +148,19 @@ impl Downloader for ReqwestDownloader {
// common case): String::from_utf8 reinterprets the Vec in place,
// whereas from_utf8_lossy always allocates + copies. Fall back to
// lossy only on genuinely invalid bytes, preserving U+FFFD behavior.
let body_len = buf.len();
let body = match String::from_utf8(buf) {
Ok(s) => s,
Err(e) => String::from_utf8_lossy(e.as_bytes()).into_owned(),
};
// One DEBUG per request (dogfood ring). Query stripped; body length +
// status only — never the body. Gated behind the Debug-level bump.
log::debug!(
"{method_str} {endpoint} → {code} {body_len}B {}ms",
started.elapsed().as_millis()
);
Ok(Response::new(code, message, headers, body, url_after_redirects))
}
}

View file

@ -59,6 +59,13 @@ pub enum ContentUnavailable {
SoundCloudGoPlus,
#[error("account terminated")]
AccountTerminated,
/// The 2026 poToken/BotGuard "sign in to confirm you're not a bot" wall.
/// Its Display is kept byte-identical to the old
/// `Other("sign in to confirm you're not a bot")` so string-matching
/// callers keep working; the dedicated variant makes the wall greppable in
/// logs and distinctly classifiable in app state.
#[error("sign in to confirm you're not a bot")]
BotDetected,
#[error("unavailable: {0}")]
Other(String),
}

View file

@ -46,7 +46,14 @@ pub fn channel_info(identifier: ChannelIdentifier) -> Result<ChannelInfo, Extrac
ChannelIdentifier::Custom(c) => resolve_handle_to_channel_id(&format!("c/{c}"))?,
ChannelIdentifier::LegacyUser(u) => resolve_handle_to_channel_id(&format!("user/{u}"))?,
};
fetch_channel_browse(&resolved)
let info = fetch_channel_browse(&resolved)?;
log::info!(
"[channel {}] channel_info ok: videos={} continuation={}",
info.channel_id,
info.recent_videos.len(),
info.videos_continuation.is_some()
);
Ok(info)
}
pub fn resolve_handle_to_channel_id(url_fragment: &str) -> Result<String, ExtractionError> {
@ -113,10 +120,21 @@ pub fn fetch_channel_browse(channel_id: &str) -> Result<ChannelInfo, ExtractionE
// Videos tab is best-effort: a fetch error OR a panicked worker thread
// just leaves recent_videos empty (header still populated above).
if let Ok(Ok(videos_response)) = videos_result {
info.recent_videos = parse_videos_tab(&videos_response);
if let Some(token) = parse_videos_continuation(&videos_response) {
info.videos_continuation = Some(token);
match videos_result {
Ok(Ok(videos_response)) => {
info.recent_videos = parse_videos_tab(&videos_response, channel_id);
if let Some(token) = parse_videos_continuation(&videos_response) {
info.videos_continuation = Some(token);
}
}
Ok(Err(e)) => {
log::warn!("[channel {channel_id}] Videos-tab fetch failed ({e}); recent_videos empty (header still populated)");
}
Err(_) => {
// The worker closure can't panic by construction → invariant breach.
log::error!(
"[channel {channel_id}] Videos-tab worker thread panicked; recent_videos empty"
);
}
}
Ok(info)
@ -129,7 +147,13 @@ pub fn fetch_channel_browse(channel_id: &str) -> Result<ChannelInfo, ExtractionE
/// exhausted).
pub fn channel_videos_continuation(token: &str) -> Result<ContinuationPage, ExtractionError> {
let body = fetch_continuation_browse(token)?;
Ok(parse_channel_continuation(&body))
let page = parse_channel_continuation(&body);
log::info!(
"channel_videos_continuation ok: items={} more={}",
page.items.len(),
page.continuation.is_some()
);
Ok(page)
}
/// POST `browse` with `{"continuation": token}` (no browseId/params).
@ -170,12 +194,24 @@ fn fetch_continuation_browse(token: &str) -> Result<Value, ExtractionError> {
/// `continuationItems` array.
pub fn parse_channel_continuation(body: &Value) -> ContinuationPage {
let Some(items) = continuation_items(body, "onResponseReceivedActions") else {
// A non-empty body with no continuationItems = the pagination shape
// moved; the page returns empty and pagination silently ends.
if body.as_object().map(|m| !m.is_empty()).unwrap_or(false) {
log::warn!("channel continuation: no continuationItems found (pagination shape changed?); ending pagination");
}
return ContinuationPage::default();
};
let videos = items.iter().filter_map(parse_rich_grid_item).collect();
let videos: Vec<StreamInfoItem> = items.iter().filter_map(parse_rich_grid_item).collect();
// Aggregate renderer-migration signal: cells present but none parsed.
if !items.is_empty() && videos.is_empty() {
log::warn!(
"channel continuation: {} cell(s) but 0 parsed (renderer migration?)",
items.len()
);
}
ContinuationPage {
items: videos,
continuation: token_from_items(items),
items: videos,
}
}
@ -289,11 +325,23 @@ pub fn parse_channel_browse(channel_id: &str, body: &Value) -> ChannelInfo {
/// Handles BOTH old-style `videoRenderer` items and new-style
/// `lockupViewModel` items (YT migrated channel-videos UI to
/// lockupViewModel around 2024).
fn parse_videos_tab(body: &Value) -> Vec<StreamInfoItem> {
match selected_tab_grid_contents(body) {
Some(items) => items.iter().filter_map(parse_rich_grid_item).collect(),
None => Vec::new(),
fn parse_videos_tab(body: &Value, channel_id: &str) -> Vec<StreamInfoItem> {
let Some(items) = selected_tab_grid_contents(body) else {
// A real browse response (has `contents`) but no grid = layout change.
if body.get("contents").is_some() {
log::warn!("[channel {channel_id}] Videos-tab grid not found (layout change?); recent_videos empty");
}
return Vec::new();
};
let parsed: Vec<StreamInfoItem> = items.iter().filter_map(parse_rich_grid_item).collect();
// Aggregate renderer-migration signal: cells present but none parsed.
if !items.is_empty() && parsed.is_empty() {
log::warn!(
"[channel {channel_id}] Videos-tab grid had {} cell(s) but 0 parsed (renderer migration?)",
items.len()
);
}
parsed
}
/// The `contents[]` array of the selected channel tab's

View file

@ -60,6 +60,8 @@ pub enum DeobfError {
JsRuntimeFailed(String),
#[error("nsig output was empty (function neutered?)")]
NsigEmpty,
#[error("nsig output equalled its input (identity — deobfuscator neutered?)")]
NsigIdentity,
#[error("downloader not initialized")]
DownloaderMissing,
}

View file

@ -177,7 +177,10 @@ fn deobfuscation_function_body(
let function_base = format!("{function_name}=function");
match match_to_closing_brace(player_code, &function_base) {
Ok(body) => Ok(format!("{function_base}{body};")),
Err(_) => deobfuscation_function_body_regex(player_code, function_name),
Err(_) => {
log::debug!("nsig body: lexer brace-match failed, falling back to regex extraction");
deobfuscation_function_body_regex(player_code, function_name)
}
}
}
@ -220,6 +223,11 @@ pub fn fixup_function(function: &str) -> Result<String, DeobfError> {
.unwrap_or_default();
if first_arg.is_empty() {
// The args regex didn't capture a first argument, so the
// `if(typeof X==="undefined")return <arg>;` guard can't be stripped —
// the deobfuscator will return its input unchanged (throttled URLs).
// Fires ~once per player.js generation (build is cached).
log::warn!("nsig fixup: could not extract the function's first argument; the early-return guard cannot be stripped → deobfuscator may return its input unchanged");
return Ok(function.to_string());
}

View file

@ -108,6 +108,22 @@ impl Derived {
Derived::Nsig => &mut state.nsig_fail,
}
}
/// Short log label for the derived artifact.
fn label(&self) -> &'static str {
match self {
Derived::SigTimestamp => "signature-timestamp",
Derived::Sig => "sig",
Derived::Nsig => "nsig",
}
}
}
/// Strip the query/fragment off a player.js URL before logging. Player URLs are
/// static + user-independent (safe to log per the audit), but this keeps the
/// no-secrets discipline uniform with the rest of the crate.
fn strip_query(url: &str) -> &str {
url.split(['?', '#']).next().unwrap_or(url)
}
/// Verdict of a memo check, decided under the state lock.
@ -282,6 +298,9 @@ impl PlayerManager {
) {
Ok(result) => {
if result == "null" {
log::warn!(
"sig deobf returned \"null\" → empty signature (affected formats may 403)"
);
Ok(String::new()) // NPE: Objects.requireNonNullElse(..., "")
} else {
Ok(result)
@ -340,6 +359,21 @@ impl PlayerManager {
self.on_eval_failure(Derived::Nsig, fresh, &e);
return Err(e);
}
if deobf == obf {
// Identity output: the deobfuscator ran but returned its input
// UNCHANGED — almost always a surviving `if(typeof X==="undefined")
// return p;` guard that `fixup_function` failed to strip. Caching it
// would permanently serve THROTTLED URLs for the whole session, so
// treat it like a neutered function: DON'T cache, invalidate +
// (fresh) memoize so the rest of the open replays cheaply, and let
// the throttled formats be counted by the aggregate nsig-fallback
// WARN in populate_streams. The memo/invalidate machinery bounds
// this WARN to ~once per player.js generation per open.
let e = DeobfError::NsigIdentity;
log::warn!("nsig deobf returned its input unchanged (identity) → NOT caching (would permanently throttle); player.js likely has an unstripped guard");
self.on_eval_failure(Derived::Nsig, fresh, &e);
return Err(e);
}
{
let mut state = self.state.lock();
@ -408,6 +442,10 @@ impl PlayerManager {
// The post-cooldown probe itself failed (network).
// Re-arm the cooldown so we don't probe on every
// subsequent call while the network is down.
log::warn!(
"player.js {} post-cooldown probe failed ({fetch_err}); re-arming cooldown",
which.label()
);
let mut state = self.state.lock();
if let Some(m) = which.memo_mut(&mut state).as_mut() {
m.at = Instant::now();
@ -425,6 +463,11 @@ impl PlayerManager {
let mut state = self.state.lock();
match which.memo_mut(&mut state).as_mut() {
Some(m) => {
log::warn!(
"player.js {} still broken: YT is still serving the known-bad player.js after cooldown (player={})",
which.label(),
strip_query(&m.player_url)
);
m.at = Instant::now();
return Err(m.error.clone());
}
@ -458,6 +501,12 @@ impl PlayerManager {
// the memo so every further call within the cooldown
// replays instead of re-fetching ~1.7 MB per format.
let player_url = state.player_url.clone().unwrap_or_default();
log::warn!(
"player.js {} extraction failed ({e}); memoizing for {}s (player={})",
which.label(),
FAILURE_COOLDOWN.as_secs(),
strip_query(&player_url)
);
*which.memo_mut(&mut state) = Some(FailMemo {
player_url,
error: e.clone(),
@ -467,6 +516,12 @@ impl PlayerManager {
}
};
}
// Invariant breach: the 2-pass retry loop is bounded and should always
// resolve; exhausting it means an unexpected concurrent-invalidation storm.
log::error!(
"player.js {} unavailable after retry (concurrent cache-invalidation loop exhausted)",
which.label()
);
Err(DeobfError::FetchPlayerCode(
"player.js unavailable after retry (concurrent cache invalidation)".into(),
))
@ -482,6 +537,16 @@ impl PlayerManager {
fn on_eval_failure(&self, which: Derived, fresh: bool, error: &DeobfError) {
let mut state = self.state.lock();
let player_url = state.player_url.clone().unwrap_or_default();
log::warn!(
"player.js {} eval failed ({error}); invalidating{} (player={})",
which.label(),
if fresh {
" + memoizing (fresh download)"
} else {
" for refetch"
},
strip_query(&player_url)
);
state.invalidate();
if fresh {
*which.memo_mut(&mut state) = Some(FailMemo {
@ -550,6 +615,13 @@ impl PlayerManager {
*memo = None;
}
}
// The one INFO that makes every sig/nsig incident diagnosable: which
// player.js generation is installed + its size. Lifecycle, ~1/rotation.
log::info!(
"player.js installed: {} ({}KB, fresh)",
strip_query(&url),
code.len() / 1024
);
state.player_url = Some(url);
state.player_code = Some(code);
Ok(Ensured::Ready { fresh: true })
@ -719,6 +791,12 @@ mod tests {
// (no outer-global references), so eval succeeds for any input.
const PLAYER_GOOD: &str = r#"m85=function(p){var a=p.split("");a.reverse();return a.join("");};dummy=function(q){return Q[1];};var foo={signatureTimestamp:20244};"#;
// Parses + evals fine, but the nsig function returns its INPUT unchanged
// (identity) — the neutered-deobfuscator shape (e.g. an unstripped guard).
// Name matches regex 0 via the trailing `return Q[1]`; the extracted body
// is just `m85=function(p){return p;}`.
const PLAYER_NSIG_IDENTITY: &str = r#"m85=function(p){return p;};dummy=function(q){return Q[1];};var foo={signatureTimestamp:20244};"#;
// Parses fine but throws for EVERY input at eval time.
const PLAYER_EVAL_THROWS: &str = r#"m85=function(p){throw Error("boom");return Q[1];};"#;
@ -753,6 +831,29 @@ mod tests {
assert_eq!(stub.count(), 2, "memo must suppress refetching");
}
#[test]
fn nsig_identity_output_is_rejected_and_not_cached() {
let _g = GLOBAL_DOWNLOADER_LOCK.lock();
let stub = Arc::new(StubDownloader::new("aaaaaaaa", PLAYER_NSIG_IDENTITY));
install(&stub);
let mgr = PlayerManager::new();
// The deobfuscator returns its input unchanged → must surface as
// NsigIdentity, NOT be treated as a successful deobfuscation.
let err = mgr
.url_with_throttling_parameter_deobfuscated("vid", "https://x/?n=abc")
.unwrap_err();
assert!(matches!(err, DeobfError::NsigIdentity), "got {err:?}");
// Critically, the identity result must NOT be cached — caching it would
// serve THROTTLED URLs for the whole session (the permanent-throttle trap).
assert_eq!(
mgr.throttling_parameter_cache_size(),
0,
"identity output must never be cached"
);
}
#[test]
fn artifact_memos_are_independent() {
let _g = GLOBAL_DOWNLOADER_LOCK.lock();

View file

@ -64,10 +64,11 @@ pub fn compile_or_throw(snippet: &str) -> Result<(), DeobfError> {
/// with one string argument, returns the toString of the result.
/// Mirrors NPE `JavaScript.run(snippet, functionName, parameters)`.
pub fn run(snippet: &str, function_name: &str, parameter: &str) -> Result<String, DeobfError> {
let started = Instant::now();
let runtime = guarded_runtime().map_err(|e| DeobfError::JsRuntimeFailed(e.to_string()))?;
let context =
Context::full(&runtime).map_err(|e| DeobfError::JsRuntimeFailed(e.to_string()))?;
context.with(|ctx| -> Result<String, DeobfError> {
let out = context.with(|ctx| -> Result<String, DeobfError> {
ctx.eval::<(), _>(snippet)
.map_err(|e| DeobfError::JsRuntimeFailed(format!("eval: {e}")))?;
let func: Function = ctx
@ -80,7 +81,18 @@ pub fn run(snippet: &str, function_name: &str, parameter: &str) -> Result<String
.call((parameter,))
.map_err(|e| DeobfError::JsRuntimeFailed(format!("call {function_name}: {e}")))?;
Ok(result)
})
});
// Distinguish the interrupt-handler deadline abort (a pathological /
// looping player.js) from an ordinary eval error — both surface as a
// generic QuickJS error at the eval site. `function_name` is a deobf
// function id (e.g. "deobfuscate"), not user data.
if out.is_err() && started.elapsed() >= JS_DEADLINE {
log::warn!(
"JS deadline ({}s) hit during `{function_name}` — execution aborted (pathological player.js?)",
JS_DEADLINE.as_secs()
);
}
out
}
#[cfg(test)]

View file

@ -101,7 +101,10 @@ pub fn deobfuscate_function_body(
let function_base = format!("{function_name}=function");
match match_to_closing_brace(player_code, &function_base) {
Ok(body) => Ok(format!("{function_base}{body}")),
Err(_) => deobfuscate_with_regex(player_code, function_name),
Err(_) => {
log::debug!("sig body: lexer brace-match failed, falling back to regex extraction");
deobfuscate_with_regex(player_code, function_name)
}
}
}

View file

@ -113,10 +113,12 @@ static REGISTERED_PROVIDER: Lazy<RwLock<Option<Arc<dyn PoTokenProvider>>>> =
Lazy::new(|| RwLock::new(None));
pub fn set_po_token_provider(provider: Arc<dyn PoTokenProvider>) {
log::info!("poToken provider registered");
*REGISTERED_PROVIDER.write() = Some(provider);
}
pub fn clear_po_token_provider() {
log::info!("poToken provider cleared");
*REGISTERED_PROVIDER.write() = None;
}

View file

@ -69,7 +69,15 @@ pub fn search(query: &str, filter: SearchFilter) -> Result<SearchInfo, Extractio
}
let parsed: Value = serde_json::from_str(resp.response_body())
.map_err(|e| ExtractionError::Parsing(ParsingError::JsonShape(e.to_string())))?;
Ok(parse_search_response(query, &parsed))
let info = parse_search_response(query, &parsed);
log::info!(
"search ok: query_len={} items={} corrected={} continuation={}",
query.len(),
info.videos.len(),
info.corrected_query.is_some(),
info.continuation_token.is_some()
);
Ok(info)
}
/// Fetch the NEXT page of search results via a continuation token.
@ -105,7 +113,13 @@ pub fn search_continuation(token: &str) -> Result<ContinuationPage, ExtractionEr
}
let parsed: Value = serde_json::from_str(resp.response_body())
.map_err(|e| ExtractionError::Parsing(ParsingError::JsonShape(e.to_string())))?;
Ok(parse_search_continuation(&parsed))
let page = parse_search_continuation(&parsed);
log::info!(
"search_continuation ok: items={} more={}",
page.items.len(),
page.continuation.is_some()
);
Ok(page)
}
/// Parse a search continuation response. Items arrive under
@ -116,6 +130,9 @@ pub fn search_continuation(token: &str) -> Result<ContinuationPage, ExtractionEr
/// continuationItemRenderer carrying the next token.
pub fn parse_search_continuation(body: &Value) -> ContinuationPage {
let Some(items) = continuation_items(body, "onResponseReceivedCommands") else {
if body.as_object().map(|m| !m.is_empty()).unwrap_or(false) {
log::warn!("search continuation: no continuationItems found (shape changed?); ending pagination");
}
return ContinuationPage::default();
};
let mut info = SearchInfo::default();
@ -155,6 +172,16 @@ pub fn parse_search_response(query: &str, body: &Value) -> SearchInfo {
.and_then(|c| c.get("sectionListRenderer"))
.and_then(|c| c.get("contents"));
// A non-empty response body whose primary results path is gone = a layout
// change; we'd otherwise silently return zero results. Log query_len, never
// the query.
if primary.is_none() && body.as_object().map(|m| !m.is_empty()).unwrap_or(false) {
log::warn!(
"search: primary results path missing (layout change?); 0 results for query_len={}",
query.len()
);
}
if let Some(sections) = primary.and_then(|v| v.as_array()) {
for section in sections {
if let Some(items) = section

View file

@ -35,7 +35,7 @@ use crate::youtube::itag::{lookup as itag_lookup, ItagType};
#[cfg(test)]
use crate::youtube::itag::MediaFormat;
use crate::youtube::js::PlayerManager;
use crate::youtube::potoken::{po_token_provider, PoTokenResult};
use crate::youtube::potoken::{po_token_provider, PoTokenError, PoTokenResult};
use crate::youtube::stream_helper::{self, generate_content_playback_nonce};
use crate::youtube::xtags;
@ -128,9 +128,9 @@ pub fn stream_info_with(
options.android_streaming_pot.as_deref(),
options.android_visitor_data.as_deref(),
|| {
provider
.as_ref()
.and_then(|p| p.get_android_client_po_token(video_id).ok().flatten())
provider.as_ref().and_then(|p| {
provider_token(p.get_android_client_po_token(video_id), "ANDROID", video_id)
})
},
);
@ -157,11 +157,18 @@ pub fn stream_info_with(
// the win is the warm/success path. Worst case is a rare, bounded cold-fail
// delay — never a change in what's extracted.
let (android_result, signature_timestamp) = std::thread::scope(|s| {
let sig_ts = s.spawn(|| {
PlayerManager::instance()
.signature_timestamp(video_id)
.unwrap_or(0)
});
let sig_ts = s.spawn(
|| match PlayerManager::instance().signature_timestamp(video_id) {
Ok(ts) => ts,
Err(e) => {
// WARN, not fatal: sig-required (WEB-family) formats may 403,
// but the android-primary formats carry direct URLs. The
// timestamp also feeds the WEB metadata playbackContext.
log::warn!("[{video_id}] signature_timestamp unavailable ({e}); using 0");
0
}
},
);
let android = fetch_android(
video_id,
&localization,
@ -172,8 +179,16 @@ pub fn stream_info_with(
.map(|t| t.player_request_po_token.as_str()),
android_token.as_ref().map(|t| t.visitor_data.as_str()),
);
// A panicked worker joins as Err → 0, same as an extraction failure.
(android, sig_ts.join().unwrap_or(0))
// A panicked worker is an invariant breach (the spawned closure never
// panics by construction) → ERROR; still degrade to 0 like a failure.
let ts = match sig_ts.join() {
Ok(ts) => ts,
Err(_) => {
log::error!("[{video_id}] signature_timestamp worker thread panicked; using 0");
0
}
};
(android, ts)
});
// ── Primary player-response selection: ANDROID → VISIONOS cascade ────────
// ANDROID was the REQUIRED primary, but the 2026 poToken/BotGuard bot-wall
@ -228,9 +243,9 @@ pub fn stream_info_with(
options.ios_streaming_pot.as_deref(),
options.ios_visitor_data.as_deref(),
|| {
provider
.as_ref()
.and_then(|p| p.get_ios_client_po_token(video_id).ok().flatten())
provider.as_ref().and_then(|p| {
provider_token(p.get_ios_client_po_token(video_id), "IOS", video_id)
})
},
)
} else {
@ -250,7 +265,16 @@ pub fn stream_info_with(
ios_token.as_ref().map(|t| t.visitor_data.as_str()),
) {
Ok(r) if !is_player_response_not_valid(&r, video_id) => (Some(r), Some(ios_cpn)),
_ => (None, None),
Ok(_) => {
log::warn!(
"[{video_id}] iOS add-on response was a decoy (videoId mismatch); dropped"
);
(None, None)
}
Err(e) => {
log::warn!("[{video_id}] iOS add-on fetch failed ({e}); dropped");
(None, None)
}
}
} else {
(None, None)
@ -277,7 +301,16 @@ pub fn stream_info_with(
&cpn,
) {
Ok(r) if !is_player_response_not_valid(&r, video_id) => (Some(r), Some(cpn)),
_ => (None, None),
Ok(_) => {
log::warn!(
"[{video_id}] visionOS add-on response was a decoy (videoId mismatch); dropped"
);
(None, None)
}
Err(e) => {
log::warn!("[{video_id}] visionOS add-on fetch failed ({e}); dropped");
(None, None)
}
}
} else {
(None, None)
@ -362,6 +395,17 @@ pub fn stream_info_with(
);
populate_captions(&mut info, &player_response);
log::info!(
"[{video_id}] extraction ok: primary={} audio={} video={} video_only={}",
if primary_is_visionos {
"VISIONOS"
} else {
"ANDROID"
},
info.audio_streams.len(),
info.video_streams.len(),
info.video_only_streams.len(),
);
Ok(info)
}
@ -392,9 +436,9 @@ pub fn stream_metadata(video_id: &str) -> Result<StreamInfo, ExtractionError> {
// registered (the default) this resolves to None → anonymous reel.
let provider = po_token_provider();
let android_token: Option<PoTokenResult> = options_or_provider(None, None, None, || {
provider
.as_ref()
.and_then(|p| p.get_android_client_po_token(video_id).ok().flatten())
provider.as_ref().and_then(|p| {
provider_token(p.get_android_client_po_token(video_id), "ANDROID", video_id)
})
});
let android_cpn = generate_content_playback_nonce();
@ -432,9 +476,36 @@ pub fn stream_metadata(video_id: &str) -> Result<StreamInfo, ExtractionError> {
..StreamInfo::default()
};
populate_video_details(&mut info, &player_response);
log::info!(
"[{video_id}] stream_metadata ok: title_len={} views={} duration={}s",
info.name.len(),
info.view_count,
info.duration_seconds,
);
Ok(info)
}
/// Unwrap a PoTokenProvider result, logging a WARN on the Err arm the old
/// `.ok().flatten()` swallowed silently. `Ok(None)` = provider declined (go
/// anonymous, no log); `Err` = provider tried and failed (still go anonymous,
/// but it's a degradation worth a breadcrumb). Never logs the token — only the
/// error kind + client + videoId.
fn provider_token(
result: Result<Option<PoTokenResult>, PoTokenError>,
client: &str,
video_id: &str,
) -> Option<PoTokenResult> {
match result {
Ok(opt) => opt,
Err(e) => {
log::warn!(
"[{video_id}] {client} poToken provider errored ({e}); continuing anonymous"
);
None
}
}
}
fn options_or_provider(
opt_player_token: Option<&str>,
opt_streaming_token: Option<&str>,
@ -561,13 +632,21 @@ fn fetch_web_metadata(
content_country: &ContentCountry,
signature_timestamp: i32,
) -> Value {
stream_helper::get_web_metadata_player_response(
match stream_helper::get_web_metadata_player_response(
video_id,
localization,
content_country,
signature_timestamp,
)
.unwrap_or(Value::Null)
) {
Ok(v) => v,
Err(e) => {
// WEB metadata is best-effort; on failure we fall back to the
// primary response's videoDetails thumbnails and lose upload
// date / category / hi-res thumbnails. Also masks a WEB-client wall.
log::warn!("[{video_id}] WEB metadata fetch failed ({e}); upload date/category/hi-res thumbnails unavailable");
Value::Null
}
}
}
fn check_playability_status(player_response: &Value) -> Result<(), ExtractionError> {
@ -583,7 +662,7 @@ fn check_playability_status(player_response: &Value) -> Result<(), ExtractionErr
let mapped = match status_code {
"LOGIN_REQUIRED" => {
if reason_lc.contains("a bot") {
ContentUnavailable::Other("sign in to confirm you're not a bot".into())
ContentUnavailable::BotDetected
} else if reason_lc.contains("inappropriate") {
ContentUnavailable::AgeRestricted
} else if reason_lc.contains("private") {
@ -657,15 +736,28 @@ fn select_primary(
// ANDROID unusable → drop the (likely poisoned) visitorData, then try
// VISIONOS as the primary. On any VISIONOS failure, surface the ORIGINAL
// ANDROID error rather than the visionOS one.
// `android_error`'s Display carries the playabilityStatus reason (the
// choke point in exceptions.rs strips any URL, so no stream URL leaks).
log::warn!("[{video_id}] ANDROID primary unusable ({android_error}); trying VISIONOS");
on_fallback();
match fetch_visionos() {
Ok(resp) if primary_response_usable(&resp, video_id).is_ok() => Ok((resp, true)),
_ => Err(android_error),
Ok(resp) if primary_response_usable(&resp, video_id).is_ok() => {
log::info!("[{video_id}] primary=VISIONOS (ANDROID fallback succeeded)");
Ok((resp, true))
}
_ => {
log::warn!("[{video_id}] extraction failed: ANDROID and VISIONOS both unusable ({android_error})");
Err(android_error)
}
}
}
fn populate_video_details(info: &mut StreamInfo, player_response: &Value) {
let Some(vd) = player_response.get("videoDetails") else {
log::warn!(
"[{}] player response had no videoDetails; title/uploader/duration left empty",
info.video_id
);
return;
};
if let Some(s) = vd.get("title").and_then(|v| v.as_str()) {
@ -759,6 +851,22 @@ fn populate_microformat(info: &mut StreamInfo, web_metadata: &Value) {
}
}
/// Per-EXTRACTION accumulator for per-format URL-processing outcomes, so the
/// degradations that happen inside the per-format loop are logged ONCE (in
/// `populate_streams`) as aggregate counters instead of spamming a line per
/// format. Threaded through `process_url` / `build_*`; never logged from inside
/// the loop.
#[derive(Default)]
struct UrlProcessStats {
/// Formats that shipped the THROTTLED original URL because nsig deobf was
/// unavailable (`url_with_throttling_parameter_deobfuscated` Err).
nsig_fallback: u32,
/// Formats that took the (android-primary-rare) signatureCipher path.
cipher_path: u32,
/// signatureCipher-path formats dropped because sig deobf failed.
cipher_sig_failed: u32,
}
/// One client's streamingData plus the tags every format from it carries.
/// Holds borrowed `&Value`s into the (function-lived) player responses.
struct FormatSource<'a> {
@ -794,9 +902,13 @@ fn populate_streams(
sources: &[FormatSource],
video_id: &str,
) -> Result<(), ExtractionError> {
// Per-call accumulator — every per-format degradation is counted here and
// logged ONCE below, never per iteration.
let mut stats = UrlProcessStats::default();
// Progressive: streamingData.formats[]
for (fmt, _client, cpn, pot) in merge_formats(sources, "formats") {
if let Some(stream) = build_video_progressive(fmt, video_id, cpn, pot)? {
if let Some(stream) = build_video_progressive(fmt, video_id, cpn, pot, &mut stats)? {
push_video_dedup(&mut info.video_streams, stream);
}
}
@ -808,15 +920,58 @@ fn populate_streams(
.and_then(|v| v.as_str())
.unwrap_or("");
if mime.starts_with("audio/") {
if let Some(audio) = build_audio(fmt, video_id, cpn, pot)? {
if let Some(audio) = build_audio(fmt, video_id, cpn, pot, &mut stats)? {
push_audio_dedup(&mut info.audio_streams, audio);
}
} else if mime.starts_with("video/") {
if let Some(video) = build_video_only(fmt, video_id, cpn, pot)? {
if let Some(video) = build_video_only(fmt, video_id, cpn, pot, &mut stats)? {
push_video_dedup(&mut info.video_only_streams, video);
}
}
}
// ── Aggregate degradation WARNs (one line each per extraction) ──────────
if stats.nsig_fallback > 0 {
log::warn!(
"[{video_id}] {} format(s) shipped THROTTLED URLs (nsig deobf unavailable)",
stats.nsig_fallback
);
}
if stats.cipher_path > 0 {
log::warn!(
"[{video_id}] {} format(s) took the signatureCipher path ({} sig-deobf failure(s))",
stats.cipher_path,
stats.cipher_sig_failed
);
}
let total = info.video_streams.len() + info.audio_streams.len() + info.video_only_streams.len();
if total == 0 {
// Playability passed but nothing built — report the raw per-source
// format counts YT actually returned so a "why no streams" incident is
// diagnosable (itag-bank miss vs empty streamingData vs all-cipher).
let counts: Vec<String> = sources
.iter()
.map(|s| {
let f = s
.streaming_data
.get("formats")
.and_then(|v| v.as_array())
.map(|a| a.len())
.unwrap_or(0);
let af = s
.streaming_data
.get("adaptiveFormats")
.and_then(|v| v.as_array())
.map(|a| a.len())
.unwrap_or(0);
format!("{}={}+{}", s.client, f, af)
})
.collect();
log::warn!(
"[{video_id}] playability OK but ZERO usable streams built (per-source formats+adaptive: {})",
counts.join(" ")
);
}
Ok(())
}
@ -914,12 +1069,15 @@ fn process_url(
video_id: &str,
cpn: &str,
pot: Option<&str>,
stats: &mut UrlProcessStats,
) -> Result<Option<String>, ExtractionError> {
let mut url = if let Some(u) = raw_format.get("url").and_then(|v| v.as_str()) {
u.to_string()
} else {
// signatureCipher path — WEB-family only; not exercised in the
// Android-primary flow but mirror NPE's behavior for completeness.
// Counted per-extraction (aggregate WARN in populate_streams).
stats.cipher_path += 1;
let cipher_str = raw_format
.get("signatureCipher")
.or_else(|| raw_format.get("cipher"))
@ -940,7 +1098,10 @@ fn process_url(
// the Android-primary flow.)
let deobf = match PlayerManager::instance().deobfuscate_signature(video_id, s) {
Ok(d) => d,
Err(_) => return Ok(None),
Err(_) => {
stats.cipher_sig_failed += 1;
return Ok(None);
}
};
format!("{base}&{sp}={deobf}")
};
@ -956,9 +1117,19 @@ fn process_url(
// zero network instead of re-downloading ~1.7 MB per format, and retries
// after a cooldown / as soon as a new player.js ships. (NPE parity; straw
// audits 2026-07-04 + 2026-07-28 H2.)
url = PlayerManager::instance()
url = match PlayerManager::instance()
.url_with_throttling_parameter_deobfuscated(video_id, &url)
.unwrap_or(url);
{
Ok(u) => u,
Err(_e) => {
// nsig deobf unavailable (fetch/build/eval/identity failure) → ship
// the THROTTLED original URL. YouTube still serves it, rate-limited.
// Counted per-extraction; populate_streams emits ONE aggregate WARN.
// Deliberately NOT logged here (per-format = spam).
stats.nsig_fallback += 1;
url
}
};
let sep_cpn = if url.contains('?') { '&' } else { '?' };
url = format!("{url}{sep_cpn}cpn={cpn}");
@ -987,12 +1158,13 @@ fn build_video_progressive(
video_id: &str,
cpn: &str,
pot: Option<&str>,
stats: &mut UrlProcessStats,
) -> Result<Option<VideoStream>, ExtractionError> {
let itag_id = fmt.get("itag").and_then(|v| v.as_u64()).unwrap_or(0) as u32;
let Some(itag) = itag_lookup(itag_id) else {
return Ok(None);
};
let Some(url) = process_url(fmt, video_id, cpn, pot)? else {
let Some(url) = process_url(fmt, video_id, cpn, pot, stats)? else {
return Ok(None);
};
Ok(Some(VideoStream {
@ -1019,6 +1191,7 @@ fn build_video_only(
video_id: &str,
cpn: &str,
pot: Option<&str>,
stats: &mut UrlProcessStats,
) -> Result<Option<VideoStream>, ExtractionError> {
let itag_id = fmt.get("itag").and_then(|v| v.as_u64()).unwrap_or(0) as u32;
let Some(itag) = itag_lookup(itag_id) else {
@ -1027,7 +1200,7 @@ fn build_video_only(
if itag.item_type != ItagType::VideoOnly {
return Ok(None);
}
let Some(url) = process_url(fmt, video_id, cpn, pot)? else {
let Some(url) = process_url(fmt, video_id, cpn, pot, stats)? else {
return Ok(None);
};
Ok(Some(VideoStream {
@ -1054,6 +1227,7 @@ fn build_audio(
video_id: &str,
cpn: &str,
pot: Option<&str>,
stats: &mut UrlProcessStats,
) -> Result<Option<AudioStream>, ExtractionError> {
let itag_id = fmt.get("itag").and_then(|v| v.as_u64()).unwrap_or(0) as u32;
let Some(itag) = itag_lookup(itag_id) else {
@ -1062,7 +1236,7 @@ fn build_audio(
if itag.item_type != ItagType::Audio {
return Ok(None);
}
let Some(url) = process_url(fmt, video_id, cpn, pot)? else {
let Some(url) = process_url(fmt, video_id, cpn, pot, stats)? else {
return Ok(None);
};
let audio_track = fmt.get("audioTrack");
@ -1214,6 +1388,26 @@ mod tests {
}
}
#[test]
fn playability_bot_wall_maps_to_bot_detected() {
// The 2026 poToken/BotGuard wall on the pot-less client. It must map to
// the dedicated BotDetected variant (greppable / classifiable), and its
// Display must stay byte-identical to the old Other(...) string so
// string-matching callers keep working.
let resp = json!({
"playabilityStatus": {
"status": "LOGIN_REQUIRED",
"reason": "Sign in to confirm youre not a bot. This helps protect our community."
}
});
match check_playability_status(&resp).unwrap_err() {
ExtractionError::ContentUnavailable(ref cu @ ContentUnavailable::BotDetected) => {
assert_eq!(cu.to_string(), "sign in to confirm you're not a bot");
}
other => panic!("expected BotDetected, got {other:?}"),
}
}
#[test]
fn decoy_detected() {
let resp = json!({"videoDetails": {"videoId": "DIFFERENT_ID"}});
@ -1560,7 +1754,9 @@ mod tests {
#[test]
fn xtags_descriptive_sets_track_type_and_is_descriptive() {
let fmt = audio_fmt(Some("ChQKBWFjb250EgtkZXNjcmlwdGl2ZQ"), true);
let a = build_audio(&fmt, "vid", "cpn", None).unwrap().unwrap();
let a = build_audio(&fmt, "vid", "cpn", None, &mut UrlProcessStats::default())
.unwrap()
.unwrap();
assert_eq!(a.track_type, Some(AudioTrackType::Descriptive));
assert!(a.is_descriptive);
}
@ -1570,7 +1766,9 @@ mod tests {
// acont=dubbed → Dubbed + is_descriptive false, even though
// audioIsDefault=false would make the legacy heuristic say "descriptive".
let fmt = audio_fmt(Some("Cg8KBWFjb250EgZkdWJiZWQ"), false);
let a = build_audio(&fmt, "vid", "cpn", None).unwrap().unwrap();
let a = build_audio(&fmt, "vid", "cpn", None, &mut UrlProcessStats::default())
.unwrap()
.unwrap();
assert_eq!(a.track_type, Some(AudioTrackType::Dubbed));
assert!(!a.is_descriptive);
}
@ -1578,7 +1776,9 @@ mod tests {
#[test]
fn xtags_original_maps_to_original() {
let fmt = audio_fmt(Some("ChEKBWFjb250EghvcmlnaW5hbA"), true);
let a = build_audio(&fmt, "vid", "cpn", None).unwrap().unwrap();
let a = build_audio(&fmt, "vid", "cpn", None, &mut UrlProcessStats::default())
.unwrap()
.unwrap();
assert_eq!(a.track_type, Some(AudioTrackType::Original));
assert!(!a.is_descriptive);
}
@ -1586,15 +1786,27 @@ mod tests {
#[test]
fn absent_xtags_falls_back_to_audio_is_default_heuristic() {
// No xtags → track_type None → is_descriptive == !audioIsDefault.
let a = build_audio(&audio_fmt(None, false), "vid", "cpn", None)
.unwrap()
.unwrap();
let a = build_audio(
&audio_fmt(None, false),
"vid",
"cpn",
None,
&mut UrlProcessStats::default(),
)
.unwrap()
.unwrap();
assert_eq!(a.track_type, None);
assert!(a.is_descriptive); // !false
let a = build_audio(&audio_fmt(None, true), "vid", "cpn", None)
.unwrap()
.unwrap();
let a = build_audio(
&audio_fmt(None, true),
"vid",
"cpn",
None,
&mut UrlProcessStats::default(),
)
.unwrap()
.unwrap();
assert_eq!(a.track_type, None);
assert!(!a.is_descriptive); // !true
}
@ -1602,9 +1814,15 @@ mod tests {
#[test]
fn unparseable_xtags_falls_back_to_heuristic() {
// Garbage xtags → extract_audio_track_type None → heuristic used.
let a = build_audio(&audio_fmt(Some("!!!not-b64!!!"), false), "vid", "cpn", None)
.unwrap()
.unwrap();
let a = build_audio(
&audio_fmt(Some("!!!not-b64!!!"), false),
"vid",
"cpn",
None,
&mut UrlProcessStats::default(),
)
.unwrap()
.unwrap();
assert_eq!(a.track_type, None);
assert!(a.is_descriptive);
}

View file

@ -142,8 +142,21 @@ fn get_visitor_data(
// best-effort None (the caller then proceeds without visitorData). An
// expired-but-present cache entry is deliberately NOT served on a failed
// refetch: a stale visitorData is the thing we're rotating away from.
let parsed = post_youtube(&url, &body, headers).ok()?;
let visitor = visitor_data_from_response(&parsed)?;
// WARN because losing visitorData weakens attestation and kneecaps the
// visionOS bot-wall survivor. post_youtube already DEBUG-logged the
// HTTP-level detail; this is the semantic degradation. `domain` is a
// static endpoint constant (no secrets).
let parsed = match post_youtube(&url, &body, headers) {
Ok(p) => p,
Err(_e) => {
log::warn!("visitorData unavailable ({domain}visitor_id fetch failed); proceeding without it (attestation/visionOS weakened)");
return None;
}
};
let Some(visitor) = visitor_data_from_response(&parsed) else {
log::warn!("visitorData unavailable ({domain}visitor_id response had no visitorData); proceeding without it");
return None;
};
*VISITOR_DATA_CACHE.write() = Some(CachedVisitorData {
value: visitor.clone(),
at: std::time::Instant::now(),
@ -157,6 +170,9 @@ fn get_visitor_data(
/// the primary path, and since that failure aborts extraction the value would
/// otherwise never self-heal.
pub(crate) fn reset_visitor_data_cache() {
// Lifecycle INFO: the self-heal trigger. Covers both the primary-cascade
// path and the stream_metadata twin path.
log::info!("visitorData cache reset (primary response rejected; next fetch mints fresh)");
*VISITOR_DATA_CACHE.write() = None;
}
@ -459,14 +475,32 @@ fn post_youtube(
// put it in an error string (they reach Kotlin exception messages
// and logs). Scheme+host+path identifies the endpoint just fine.
let endpoint = url.split(['?', '#']).next().unwrap_or(url);
// body_len is the bot-wall tell (an HTML challenge page has a
// distinctive size vs a JSON error). DEBUG — per-request breadcrumb;
// the semantic WARN is emitted by the caller.
log::debug!(
"post_youtube {endpoint} → HTTP {} ({}B body)",
resp.response_code(),
resp.response_body().len()
);
return Err(ExtractionError::Network(NetworkError::Transport(format!(
"HTTP {} from {endpoint}",
resp.response_code()
))));
}
let parsed: Value = serde_json::from_str(resp.response_body())
.map_err(|e| ExtractionError::Parsing(ParsingError::JsonShape(e.to_string())))?;
Ok(parsed)
match serde_json::from_str(resp.response_body()) {
Ok(parsed) => Ok(parsed),
Err(e) => {
let endpoint = url.split(['?', '#']).next().unwrap_or(url);
log::debug!(
"post_youtube {endpoint} → 200 but body was not JSON ({}B): {e}",
resp.response_body().len()
);
Err(ExtractionError::Parsing(ParsingError::JsonShape(
e.to_string(),
)))
}
}
}
#[cfg(test)]