mirror of
https://github.com/nimbold/Firelink.git
synced 2026-08-28 19:47:26 +00:00
fix(downloads): harden aria2 diagnostics
- add stage-correlated metadata, DNS, admission, retry, and poller logs - classify resolver, range, and HTTP failures without leaking sensitive data - fence slow Aria2 admission and terminal polling against stale lifecycle state - record proxy route and requested versus effective connection telemetry
This commit is contained in:
+401
-70
@@ -1996,6 +1996,7 @@ async fn fetch_metadata(
|
|||||||
properties_window::ensure_main_window(&caller)?;
|
properties_window::ensure_main_window(&caller)?;
|
||||||
ensure_reqwest_crypto_provider();
|
ensure_reqwest_crypto_provider();
|
||||||
|
|
||||||
|
let metadata_started = Instant::now();
|
||||||
let mut current_url = url.clone();
|
let mut current_url = url.clone();
|
||||||
let original_origin = reqwest::Url::parse(&url).ok();
|
let original_origin = reqwest::Url::parse(&url).ok();
|
||||||
let mut redirects = 0;
|
let mut redirects = 0;
|
||||||
@@ -2007,17 +2008,28 @@ async fn fetch_metadata(
|
|||||||
let defer_cookies = defer_cookies.unwrap_or(false);
|
let defer_cookies = defer_cookies.unwrap_or(false);
|
||||||
let mut send_cookies = !defer_cookies || !cookies_available;
|
let mut send_cookies = !defer_cookies || !cookies_available;
|
||||||
let mut cookie_retry_attempted = false;
|
let mut cookie_retry_attempted = false;
|
||||||
|
log::info!(
|
||||||
|
"metadata [stage=metadata operation=start host={} credentials_available={} deferred_cookies={} proxy_route={}]",
|
||||||
|
original_origin
|
||||||
|
.as_ref()
|
||||||
|
.and_then(|value| value.host_str())
|
||||||
|
.unwrap_or("<unknown host>"),
|
||||||
|
cookies_available,
|
||||||
|
defer_cookies,
|
||||||
|
crate::queue::proxy_route_for_log(proxy.as_deref())
|
||||||
|
);
|
||||||
let res;
|
let res;
|
||||||
|
|
||||||
loop {
|
loop {
|
||||||
if redirects >= 5 {
|
if redirects >= 5 {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"metadata [stage=metadata host={} redirects={} error_code=redirect_limit]",
|
"metadata [stage=metadata operation=redirect_limit host={} redirects={} error_code=redirect_limit elapsed_ms={}]",
|
||||||
reqwest::Url::parse(¤t_url)
|
reqwest::Url::parse(¤t_url)
|
||||||
.ok()
|
.ok()
|
||||||
.and_then(|value| value.host_str().map(str::to_string))
|
.and_then(|value| value.host_str().map(str::to_string))
|
||||||
.unwrap_or_else(|| "<unknown host>".to_string()),
|
.unwrap_or_else(|| "<unknown host>".to_string()),
|
||||||
redirects
|
redirects,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err("Too many redirects".to_string());
|
return Err("Too many redirects".to_string());
|
||||||
}
|
}
|
||||||
@@ -2029,7 +2041,21 @@ async fn fetch_metadata(
|
|||||||
if proxy.eq_ignore_ascii_case("none") {
|
if proxy.eq_ignore_ascii_case("none") {
|
||||||
builder = builder.no_proxy();
|
builder = builder.no_proxy();
|
||||||
} else {
|
} else {
|
||||||
builder = builder.proxy(reqwest::Proxy::all(proxy).map_err(|e| e.to_string())?);
|
let proxy = match reqwest::Proxy::all(proxy) {
|
||||||
|
Ok(proxy) => proxy,
|
||||||
|
Err(error) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=client result=failed host={} error_code=proxy_configuration elapsed_ms={}]",
|
||||||
|
reqwest::Url::parse(¤t_url)
|
||||||
|
.ok()
|
||||||
|
.and_then(|value| value.host_str().map(str::to_string))
|
||||||
|
.unwrap_or_else(|| "<unknown host>".to_string()),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(crate::redact_sensitive_text(&error.to_string()));
|
||||||
|
}
|
||||||
|
};
|
||||||
|
builder = builder.proxy(proxy);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -2044,18 +2070,49 @@ async fn fetch_metadata(
|
|||||||
builder = builder.user_agent("Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/150.0.0.0 Safari/537.36");
|
builder = builder.user_agent("Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/150.0.0.0 Safari/537.36");
|
||||||
}
|
}
|
||||||
|
|
||||||
let parsed_current_url = reqwest::Url::parse(¤t_url)
|
let parsed_current_url = match reqwest::Url::parse(¤t_url) {
|
||||||
.map_err(|_| "SSRF blocked: Invalid URL".to_string())?;
|
Ok(parsed) => parsed,
|
||||||
|
Err(_) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=parse host={} result=failed error_code=invalid_url elapsed_ms={}]",
|
||||||
|
"<unknown host>",
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err("SSRF blocked: Invalid URL".to_string());
|
||||||
|
}
|
||||||
|
};
|
||||||
let metadata_host = parsed_current_url
|
let metadata_host = parsed_current_url
|
||||||
.host_str()
|
.host_str()
|
||||||
.unwrap_or("<unknown host>")
|
.unwrap_or("<unknown host>")
|
||||||
.to_string();
|
.to_string();
|
||||||
|
let dns_started = Instant::now();
|
||||||
let resolved_addr = match parsed_current_url.scheme() {
|
let resolved_addr = match parsed_current_url.scheme() {
|
||||||
"http" | "https" => validate_url_ssrf(¤t_url).await?,
|
"http" | "https" => validate_url_ssrf(¤t_url).await,
|
||||||
"ftp" | "sftp" => resolve_and_validate_url_host(&parsed_current_url)
|
"ftp" | "sftp" => resolve_and_validate_url_host(&parsed_current_url)
|
||||||
.await
|
.await
|
||||||
.map(Some)?,
|
.map(Some),
|
||||||
_ => return Err("Unsupported URL scheme".to_string()),
|
_ => Err("Unsupported URL scheme".to_string()),
|
||||||
|
};
|
||||||
|
let resolved_addr = match resolved_addr {
|
||||||
|
Ok(resolved_addr) => {
|
||||||
|
log::info!(
|
||||||
|
"metadata [stage=dns operation=resolve host={} result=ok elapsed_ms={} total_elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
dns_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
resolved_addr
|
||||||
|
}
|
||||||
|
Err(error) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=dns operation=resolve host={} result=failed error_code={} elapsed_ms={} total_elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
metadata_error_code(&error),
|
||||||
|
dns_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(error);
|
||||||
|
}
|
||||||
};
|
};
|
||||||
|
|
||||||
if let Some((host, addr)) = resolved_addr {
|
if let Some((host, addr)) = resolved_addr {
|
||||||
@@ -2089,7 +2146,18 @@ async fn fetch_metadata(
|
|||||||
};
|
};
|
||||||
builder = builder.default_headers(header_map);
|
builder = builder.default_headers(header_map);
|
||||||
|
|
||||||
let client = builder.build().map_err(|e| e.to_string())?;
|
let client = match builder.build() {
|
||||||
|
Ok(client) => client,
|
||||||
|
Err(error) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=client result=failed host={} error_code={} elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
reqwest_error_code(&error),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(crate::redact_sensitive_text(&error.to_string()));
|
||||||
|
}
|
||||||
|
};
|
||||||
let request_url = current_url.clone();
|
let request_url = current_url.clone();
|
||||||
|
|
||||||
let build_get_range = || {
|
let build_get_range = || {
|
||||||
@@ -2114,21 +2182,52 @@ async fn fetch_metadata(
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
let head_started = Instant::now();
|
||||||
let mut current_res = match head_req.send().await {
|
let mut current_res = match head_req.send().await {
|
||||||
Ok(response) => response,
|
Ok(response) => {
|
||||||
Err(head_error) => build_get_range().send().await.map_err(|get_error| {
|
log::info!(
|
||||||
log::warn!(
|
"metadata [stage=metadata operation=head host={} result=ok status={} elapsed_ms={} total_elapsed_ms={}]",
|
||||||
"metadata [stage=metadata host={} error_code=head_{}+get_{}]",
|
|
||||||
metadata_host,
|
metadata_host,
|
||||||
reqwest_error_code(&head_error),
|
response.status().as_u16(),
|
||||||
reqwest_error_code(&get_error)
|
head_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
format!(
|
response
|
||||||
"HEAD metadata request failed ({}); ranged GET fallback failed ({})",
|
}
|
||||||
reqwest_error_code(&head_error),
|
Err(head_error) => {
|
||||||
reqwest_error_code(&get_error)
|
let head_elapsed_ms = head_started.elapsed().as_millis();
|
||||||
)
|
let get_started = Instant::now();
|
||||||
})?,
|
match build_get_range().send().await {
|
||||||
|
Ok(response) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=head result=fallback host={} error_code={} head_elapsed_ms={} get_status={} get_elapsed_ms={} total_elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
reqwest_error_code(&head_error),
|
||||||
|
head_elapsed_ms,
|
||||||
|
response.status().as_u16(),
|
||||||
|
get_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
response
|
||||||
|
}
|
||||||
|
Err(get_error) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=head_get_fallback host={} result=failed error_code=head_{}+get_{} head_elapsed_ms={} get_elapsed_ms={} total_elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
reqwest_error_code(&head_error),
|
||||||
|
reqwest_error_code(&get_error),
|
||||||
|
head_elapsed_ms,
|
||||||
|
get_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(format!(
|
||||||
|
"HEAD metadata request failed ({}); ranged GET fallback failed ({})",
|
||||||
|
reqwest_error_code(&head_error),
|
||||||
|
reqwest_error_code(&get_error)
|
||||||
|
));
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
};
|
};
|
||||||
|
|
||||||
if retry_metadata_with_cookies(
|
if retry_metadata_with_cookies(
|
||||||
@@ -2140,6 +2239,12 @@ async fn fetch_metadata(
|
|||||||
&mut current_url,
|
&mut current_url,
|
||||||
&mut redirects,
|
&mut redirects,
|
||||||
) {
|
) {
|
||||||
|
log::info!(
|
||||||
|
"metadata [stage=metadata operation=credential_retry host={} redirect_count={} elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
redirects,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
// Browser captures may carry a large cookie jar even when the
|
// Browser captures may carry a large cookie jar even when the
|
||||||
// direct download is public. Probe without it first so a server
|
// direct download is public. Probe without it first so a server
|
||||||
// or proxy header limit cannot turn harmless metadata into the
|
// or proxy header limit cannot turn harmless metadata into the
|
||||||
@@ -2156,14 +2261,29 @@ async fn fetch_metadata(
|
|||||||
}
|
}
|
||||||
|
|
||||||
if needs_fallback {
|
if needs_fallback {
|
||||||
current_res = build_get_range().send().await.map_err(|error| {
|
let get_started = Instant::now();
|
||||||
log::warn!(
|
current_res = match build_get_range().send().await {
|
||||||
"metadata [stage=metadata host={} error_code=get_{}]",
|
Ok(response) => {
|
||||||
metadata_host,
|
log::info!(
|
||||||
reqwest_error_code(&error)
|
"metadata [stage=metadata operation=get_range host={} result=ok status={} elapsed_ms={} total_elapsed_ms={}]",
|
||||||
);
|
metadata_host,
|
||||||
error.to_string()
|
response.status().as_u16(),
|
||||||
})?;
|
get_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
response
|
||||||
|
}
|
||||||
|
Err(error) => {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=get_range host={} result=failed error_code={} elapsed_ms={} total_elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
reqwest_error_code(&error),
|
||||||
|
get_started.elapsed().as_millis(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(error.to_string());
|
||||||
|
}
|
||||||
|
};
|
||||||
|
|
||||||
if retry_metadata_with_cookies(
|
if retry_metadata_with_cookies(
|
||||||
current_res.status(),
|
current_res.status(),
|
||||||
@@ -2174,6 +2294,12 @@ async fn fetch_metadata(
|
|||||||
&mut current_url,
|
&mut current_url,
|
||||||
&mut redirects,
|
&mut redirects,
|
||||||
) {
|
) {
|
||||||
|
log::info!(
|
||||||
|
"metadata [stage=metadata operation=credential_retry host={} redirect_count={} elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
redirects,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
// HEAD is advisory. Some origins reject it while requiring
|
// HEAD is advisory. Some origins reject it while requiring
|
||||||
// the captured session for the ranged GET that follows.
|
// the captured session for the ranged GET that follows.
|
||||||
continue;
|
continue;
|
||||||
@@ -2185,12 +2311,21 @@ async fn fetch_metadata(
|
|||||||
if let Ok(loc_str) = loc.to_str() {
|
if let Ok(loc_str) = loc.to_str() {
|
||||||
if let Ok(parsed_base) = reqwest::Url::parse(¤t_url) {
|
if let Ok(parsed_base) = reqwest::Url::parse(¤t_url) {
|
||||||
if let Ok(new_url) = parsed_base.join(loc_str) {
|
if let Ok(new_url) = parsed_base.join(loc_str) {
|
||||||
|
let next_host = new_url.host_str().unwrap_or("<unknown host>");
|
||||||
|
let credential_scope = if same_origin(&parsed_base, &new_url) {
|
||||||
|
"same_origin"
|
||||||
|
} else {
|
||||||
|
"cross_origin"
|
||||||
|
};
|
||||||
current_url = new_url.to_string();
|
current_url = new_url.to_string();
|
||||||
redirects += 1;
|
redirects += 1;
|
||||||
log::debug!(
|
log::info!(
|
||||||
"metadata [stage=redirect host={} redirect_count={}]",
|
"metadata [stage=redirect operation=follow host={} next_host={} redirect_count={} credential_scope={} elapsed_ms={}]",
|
||||||
metadata_host,
|
metadata_host,
|
||||||
redirects
|
next_host,
|
||||||
|
redirects,
|
||||||
|
credential_scope,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
@@ -2206,14 +2341,20 @@ async fn fetch_metadata(
|
|||||||
.get(reqwest::header::CONTENT_TYPE)
|
.get(reqwest::header::CONTENT_TYPE)
|
||||||
.and_then(|value| value.to_str().ok()),
|
.and_then(|value| value.to_str().ok()),
|
||||||
) {
|
) {
|
||||||
|
log::warn!(
|
||||||
|
"metadata [stage=metadata operation=authentication host={} result=failed error_code=authentication elapsed_ms={}]",
|
||||||
|
metadata_host,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
return Err(error);
|
return Err(error);
|
||||||
}
|
}
|
||||||
|
|
||||||
if let Some(error) = metadata_response_error(current_res.status()) {
|
if let Some(error) = metadata_response_error(current_res.status()) {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"metadata [stage=metadata host={} status={} error_code=response]",
|
"metadata [stage=metadata operation=response host={} status={} error_code=response elapsed_ms={}]",
|
||||||
metadata_host,
|
metadata_host,
|
||||||
current_res.status().as_u16()
|
current_res.status().as_u16(),
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(error);
|
return Err(error);
|
||||||
}
|
}
|
||||||
@@ -2273,6 +2414,19 @@ async fn fetch_metadata(
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
log::info!(
|
||||||
|
"metadata [stage=metadata operation=complete host={} status={} redirects={} size_bytes={} resumable={} elapsed_ms={}]",
|
||||||
|
reqwest::Url::parse(¤t_url)
|
||||||
|
.ok()
|
||||||
|
.and_then(|value| value.host_str().map(str::to_string))
|
||||||
|
.unwrap_or_else(|| "<unknown host>".to_string()),
|
||||||
|
res.status().as_u16(),
|
||||||
|
redirects,
|
||||||
|
size_bytes,
|
||||||
|
resumable,
|
||||||
|
metadata_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
|
||||||
Ok(MetadataResponse {
|
Ok(MetadataResponse {
|
||||||
url,
|
url,
|
||||||
filename,
|
filename,
|
||||||
@@ -2296,6 +2450,25 @@ fn reqwest_error_code(error: &reqwest::Error) -> &'static str {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
fn metadata_error_code(error: &str) -> &'static str {
|
||||||
|
let lower = error.to_ascii_lowercase();
|
||||||
|
if lower.contains("dns resolution timed out") {
|
||||||
|
"dns_timeout"
|
||||||
|
} else if lower.contains("dns resolution") || lower.contains("name resolution") {
|
||||||
|
"dns"
|
||||||
|
} else if lower.contains("private/local ip") {
|
||||||
|
"ssrf_private_address"
|
||||||
|
} else if lower.contains("invalid url") {
|
||||||
|
"invalid_url"
|
||||||
|
} else if lower.contains("unsupported url scheme") {
|
||||||
|
"unsupported_scheme"
|
||||||
|
} else if lower.contains("timeout") || lower.contains("timed out") {
|
||||||
|
"timeout"
|
||||||
|
} else {
|
||||||
|
crate::retry::network_error_class(error)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
const MEDIA_METADATA_CACHE_TTL: Duration = Duration::from_secs(60);
|
const MEDIA_METADATA_CACHE_TTL: Duration = Duration::from_secs(60);
|
||||||
const MEDIA_METADATA_TIMEOUT: Duration = Duration::from_secs(55);
|
const MEDIA_METADATA_TIMEOUT: Duration = Duration::from_secs(55);
|
||||||
const MEDIA_METADATA_CACHE_MAX_ENTRIES: usize = 128;
|
const MEDIA_METADATA_CACHE_MAX_ENTRIES: usize = 128;
|
||||||
@@ -3001,11 +3174,13 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
id: &str,
|
id: &str,
|
||||||
destination: &str,
|
destination: &str,
|
||||||
) -> Result<(), String> {
|
) -> Result<(), String> {
|
||||||
|
let preflight_started = Instant::now();
|
||||||
let resolved = resolve_path(destination.trim(), app_handle);
|
let resolved = resolve_path(destination.trim(), app_handle);
|
||||||
if !is_safe_path(&resolved, app_handle) {
|
if !is_safe_path(&resolved, app_handle) {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: access preflight rejected an unsafe destination",
|
"download destination [stage=destination_access id={} operation=preflight result=failed error_code=unsafe_path elapsed_ms={}]",
|
||||||
id
|
id,
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder is not approved"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder is not approved"
|
||||||
@@ -3015,9 +3190,10 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
if !resolved.exists() {
|
if !resolved.exists() {
|
||||||
std::fs::create_dir_all(&resolved).map_err(|error| {
|
std::fs::create_dir_all(&resolved).map_err(|error| {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: could not create destination for access preflight: {}",
|
"download destination [stage=destination_access id={} operation=create_directory result=failed error_code={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
crate::redact_sensitive_text(&error.to_string())
|
destination_io_error_code(&error),
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
format!(
|
format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} grant Firelink access to the selected folder and retry"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} grant Firelink access to the selected folder and retry"
|
||||||
@@ -3027,8 +3203,9 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
|
|
||||||
let canonical = canonicalize_with_missing_components(&resolved).ok_or_else(|| {
|
let canonical = canonicalize_with_missing_components(&resolved).ok_or_else(|| {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: destination could not be canonicalized during access preflight",
|
"download destination [stage=destination_access id={} operation=canonicalize result=failed error_code=canonicalization elapsed_ms={}]",
|
||||||
id
|
id,
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
format!(
|
format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder could not be verified"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder could not be verified"
|
||||||
@@ -3036,8 +3213,9 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
})?;
|
})?;
|
||||||
if !is_safe_path(&canonical, app_handle) {
|
if !is_safe_path(&canonical, app_handle) {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: canonical destination is outside the approved roots",
|
"download destination [stage=destination_access id={} operation=canonicalize result=failed error_code=unsafe_path elapsed_ms={}]",
|
||||||
id
|
id,
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder is not approved"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected folder is not approved"
|
||||||
@@ -3045,8 +3223,9 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
}
|
}
|
||||||
if !canonical.is_dir() {
|
if !canonical.is_dir() {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: selected destination is not a directory",
|
"download destination [stage=destination_access id={} operation=validate_directory result=failed error_code=not_directory elapsed_ms={}]",
|
||||||
id
|
id,
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected destination is not a folder"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} selected destination is not a folder"
|
||||||
@@ -3072,15 +3251,16 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
|
|
||||||
if let Err(error) = probe_result {
|
if let Err(error) = probe_result {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: access probe failed: {}",
|
"download destination [stage=destination_access id={} operation=write_probe result=failed error_code={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
crate::redact_sensitive_text(&error.to_string())
|
destination_io_error_code(&error),
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
if let Err(cleanup_error) = cleanup_result {
|
if let Err(cleanup_error) = cleanup_result {
|
||||||
log::debug!(
|
log::debug!(
|
||||||
"download destination [{}]: failed to clean access probe: {}",
|
"download destination [stage=destination_access id={} operation=cleanup_probe result=failed error_code={}]",
|
||||||
id,
|
id,
|
||||||
crate::redact_sensitive_text(&cleanup_error.to_string())
|
destination_io_error_code(&cleanup_error)
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
@@ -3089,19 +3269,34 @@ fn preflight_download_destination_access<R: tauri::Runtime>(
|
|||||||
}
|
}
|
||||||
if let Err(error) = cleanup_result {
|
if let Err(error) = cleanup_result {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"download destination [{}]: access probe cleanup failed: {}",
|
"download destination [stage=destination_access id={} operation=cleanup_probe result=failed error_code={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
crate::redact_sensitive_text(&error.to_string())
|
destination_io_error_code(&error),
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} the selected folder could not be safely verified; retry"
|
"{RETRYABLE_DESTINATION_ACCESS_PREFIX} the selected folder could not be safely verified; retry"
|
||||||
));
|
));
|
||||||
}
|
}
|
||||||
|
|
||||||
log::debug!("download destination [{}]: access preflight succeeded", id);
|
log::info!(
|
||||||
|
"download destination [stage=destination_access id={} operation=preflight result=ok elapsed_ms={}]",
|
||||||
|
id,
|
||||||
|
preflight_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
Ok(())
|
Ok(())
|
||||||
}
|
}
|
||||||
|
|
||||||
|
fn destination_io_error_code(error: &std::io::Error) -> &'static str {
|
||||||
|
match error.kind() {
|
||||||
|
std::io::ErrorKind::PermissionDenied => "permission_denied",
|
||||||
|
std::io::ErrorKind::NotFound => "not_found",
|
||||||
|
std::io::ErrorKind::AlreadyExists => "already_exists",
|
||||||
|
std::io::ErrorKind::InvalidInput => "invalid_input",
|
||||||
|
_ => "io_error",
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
pub(crate) fn path_has_symlink_component(path: &std::path::Path) -> bool {
|
pub(crate) fn path_has_symlink_component(path: &std::path::Path) -> bool {
|
||||||
use std::path::Component;
|
use std::path::Component;
|
||||||
|
|
||||||
@@ -11324,6 +11519,7 @@ mod tests {
|
|||||||
media_progress_speed,
|
media_progress_speed,
|
||||||
cookie_scope_for_url, metadata_authentication_error, metadata_cookie_header_present,
|
cookie_scope_for_url, metadata_authentication_error, metadata_cookie_header_present,
|
||||||
metadata_headers, metadata_response_error,
|
metadata_headers, metadata_response_error,
|
||||||
|
metadata_error_code,
|
||||||
is_remote_torrent_source,
|
is_remote_torrent_source,
|
||||||
normalize_speed_limit_for_aria2,
|
normalize_speed_limit_for_aria2,
|
||||||
normalize_torrent_overall_upload_limit,
|
normalize_torrent_overall_upload_limit,
|
||||||
@@ -13153,6 +13349,19 @@ mod tests {
|
|||||||
);
|
);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn metadata_diagnostic_codes_preserve_dns_and_policy_boundaries() {
|
||||||
|
assert_eq!(
|
||||||
|
metadata_error_code("SSRF blocked: DNS resolution timed out"),
|
||||||
|
"dns_timeout"
|
||||||
|
);
|
||||||
|
assert_eq!(
|
||||||
|
metadata_error_code("SSRF blocked: Private/local IP not allowed"),
|
||||||
|
"ssrf_private_address"
|
||||||
|
);
|
||||||
|
assert_eq!(metadata_error_code("HEAD request timed out"), "timeout");
|
||||||
|
}
|
||||||
|
|
||||||
#[test]
|
#[test]
|
||||||
fn metadata_filename_reads_redirect_disposition_query_before_opaque_path() {
|
fn metadata_filename_reads_redirect_disposition_query_before_opaque_path() {
|
||||||
let redirected = "https://release-assets.githubusercontent.com/github-production-release-asset/1117828249/7aae36e6-00ec-4e7d-8dec-f14ace170bdb?rscd=attachment%3B+filename%3DOnionHop-3.5-macOS-arm64.dmg";
|
let redirected = "https://release-assets.githubusercontent.com/github-production-release-asset/1117828249/7aae36e6-00ec-4e7d-8dec-f14ace170bdb?rscd=attachment%3B+filename%3DOnionHop-3.5-macOS-arm64.dmg";
|
||||||
@@ -14084,6 +14293,8 @@ struct Aria2ConnectionObservation {
|
|||||||
last_refreshed_at: Option<Instant>,
|
last_refreshed_at: Option<Instant>,
|
||||||
peak_speed_bytes: f64,
|
peak_speed_bytes: f64,
|
||||||
last_completed: u64,
|
last_completed: u64,
|
||||||
|
last_logged_active_connections: Option<i32>,
|
||||||
|
last_connection_logged_at: Option<Instant>,
|
||||||
seeder: bool,
|
seeder: bool,
|
||||||
verifying: bool,
|
verifying: bool,
|
||||||
}
|
}
|
||||||
@@ -14128,6 +14339,7 @@ const ARIA2_DEGRADED_SPEED_FRACTION: f64 = 0.20;
|
|||||||
const ARIA2_CONNECTION_POOL_DEGRADED_FRACTION: f64 = 0.75;
|
const ARIA2_CONNECTION_POOL_DEGRADED_FRACTION: f64 = 0.75;
|
||||||
const ARIA2_MIN_HEALTHY_SPEED_SAMPLES: u8 = 3;
|
const ARIA2_MIN_HEALTHY_SPEED_SAMPLES: u8 = 3;
|
||||||
const ARIA2_MAX_CONSECUTIVE_RECOVERY_ATTEMPTS: u8 = 3;
|
const ARIA2_MAX_CONSECUTIVE_RECOVERY_ATTEMPTS: u8 = 3;
|
||||||
|
const ARIA2_CONNECTION_DIAGNOSTIC_INTERVAL: Duration = Duration::from_secs(30);
|
||||||
|
|
||||||
#[cfg(test)]
|
#[cfg(test)]
|
||||||
// Keep the test scenarios explicit while the production path uses the typed sample.
|
// Keep the test scenarios explicit while the production path uses the typed sample.
|
||||||
@@ -15104,8 +15316,28 @@ pub fn run() {
|
|||||||
"verifiedLength",
|
"verifiedLength",
|
||||||
"verifyIntegrityPending"
|
"verifyIntegrityPending"
|
||||||
]]);
|
]]);
|
||||||
if let Ok(active_list) = rpc_call(poll_port.load(std::sync::atomic::Ordering::Relaxed), &poll_secret, "aria2.tellActive", params).await {
|
let active_poll_started = Instant::now();
|
||||||
if let Some(active_arr) = active_list.as_array() {
|
let active_list = match rpc_call(
|
||||||
|
poll_port.load(std::sync::atomic::Ordering::Relaxed),
|
||||||
|
&poll_secret,
|
||||||
|
"aria2.tellActive",
|
||||||
|
params,
|
||||||
|
)
|
||||||
|
.await
|
||||||
|
{
|
||||||
|
Ok(active_list) => active_list,
|
||||||
|
Err(error) => {
|
||||||
|
log::warn!(
|
||||||
|
"aria2 poller [stage=poll operation=tell_active result=failed error_class={} error_code={} elapsed_ms={}]",
|
||||||
|
crate::retry::network_error_class(&error),
|
||||||
|
crate::retry::aria2_error_code(&error)
|
||||||
|
.unwrap_or_else(|| "none".to_string()),
|
||||||
|
active_poll_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
};
|
||||||
|
if let Some(active_arr) = active_list.as_array() {
|
||||||
let mut seen_ids = HashSet::new();
|
let mut seen_ids = HashSet::new();
|
||||||
let mut seen_gids = HashSet::new();
|
let mut seen_gids = HashSet::new();
|
||||||
for status_info in active_arr {
|
for status_info in active_arr {
|
||||||
@@ -15198,6 +15430,46 @@ pub fn run() {
|
|||||||
{
|
{
|
||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
|
let retry_strike = if !is_torrent {
|
||||||
|
poll_mgr.aria2_retry_strike(&id).await
|
||||||
|
} else {
|
||||||
|
0
|
||||||
|
};
|
||||||
|
if !poll_mgr.is_current_aria2_gid_mapping(gid, &mapping)
|
||||||
|
|| !poll_mgr
|
||||||
|
.is_aria2_control_epoch_current(&id, control_epoch)
|
||||||
|
.await
|
||||||
|
{
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
if !is_torrent
|
||||||
|
&& (observation.last_logged_active_connections
|
||||||
|
!= Some(active_connections)
|
||||||
|
|| observation.last_connection_logged_at.is_none_or(
|
||||||
|
|logged_at| {
|
||||||
|
now.duration_since(logged_at)
|
||||||
|
>= ARIA2_CONNECTION_DIAGNOSTIC_INTERVAL
|
||||||
|
},
|
||||||
|
))
|
||||||
|
{
|
||||||
|
log::info!(
|
||||||
|
"aria2 progress [stage=connections id={} gid={} epoch={} retry_strike={} status={} active_connections={} requested_connections={} effective_connections={} completed_bytes={} total_bytes={} speed_bytes_per_second={}]",
|
||||||
|
id,
|
||||||
|
gid,
|
||||||
|
control_epoch,
|
||||||
|
retry_strike,
|
||||||
|
status,
|
||||||
|
active_connections,
|
||||||
|
requested_connections,
|
||||||
|
effective_connections,
|
||||||
|
completed,
|
||||||
|
total,
|
||||||
|
speed_bytes
|
||||||
|
);
|
||||||
|
observation.last_logged_active_connections =
|
||||||
|
Some(active_connections);
|
||||||
|
observation.last_connection_logged_at = Some(now);
|
||||||
|
}
|
||||||
let torrent_telemetry = if is_torrent {
|
let torrent_telemetry = if is_torrent {
|
||||||
if !telemetry_hydrated.contains(&id) {
|
if !telemetry_hydrated.contains(&id) {
|
||||||
match load_persisted_torrent_item(
|
match load_persisted_torrent_item(
|
||||||
@@ -15423,10 +15695,12 @@ pub fn run() {
|
|||||||
.await
|
.await
|
||||||
{
|
{
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 connection recovery [{}] for gid {} failed: {}",
|
"aria2 connection recovery [stage=recovery id={} gid={} operation=refresh result=failed error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
error
|
crate::retry::network_error_class(&error),
|
||||||
|
crate::retry::aria2_error_code(&error)
|
||||||
|
.unwrap_or_else(|| "none".to_string())
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -15454,10 +15728,12 @@ pub fn run() {
|
|||||||
Ok(status) => status,
|
Ok(status) => status,
|
||||||
Err(error) => {
|
Err(error) => {
|
||||||
log::debug!(
|
log::debug!(
|
||||||
"aria2 poller reconciliation [{}]: could not query gid {}: {}",
|
"aria2 poller [stage=poll operation=tell_status id={} gid={} result=failed error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
error
|
crate::retry::network_error_class(&error),
|
||||||
|
crate::retry::aria2_error_code(&error)
|
||||||
|
.unwrap_or_else(|| "none".to_string())
|
||||||
);
|
);
|
||||||
let recovery_allowed = missing_gid_recovery_at
|
let recovery_allowed = missing_gid_recovery_at
|
||||||
.get(&id)
|
.get(&id)
|
||||||
@@ -15493,10 +15769,16 @@ pub fn run() {
|
|||||||
}
|
}
|
||||||
Err(recovery_error) => {
|
Err(recovery_error) => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 poller reconciliation [{}]: payload recovery for missing gid {} failed: {}",
|
"aria2 poller [stage=recovery operation=missing_gid id={} gid={} result=failed error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
recovery_error
|
crate::retry::network_error_class(
|
||||||
|
&recovery_error,
|
||||||
|
),
|
||||||
|
crate::retry::aria2_error_code(
|
||||||
|
&recovery_error,
|
||||||
|
)
|
||||||
|
.unwrap_or_else(|| "none".to_string())
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -15505,16 +15787,18 @@ pub fn run() {
|
|||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
};
|
};
|
||||||
if let Some(mapping) = poll_mgr
|
let Some(mapping) = poll_mgr
|
||||||
.aria2_gid_mapping(&gid)
|
.aria2_gid_mapping(&gid)
|
||||||
.filter(|mapping| mapping.id == id)
|
.filter(|mapping| mapping.id == id)
|
||||||
|
else {
|
||||||
|
continue;
|
||||||
|
};
|
||||||
|
let is_torrent = poll_mgr.aria2_is_torrent(&id).await;
|
||||||
|
if is_torrent
|
||||||
|
&& poll_mgr
|
||||||
|
.is_aria2_control_epoch_current(&id, mapping.epoch)
|
||||||
|
.await
|
||||||
{
|
{
|
||||||
let is_torrent = poll_mgr.aria2_is_torrent(&id).await;
|
|
||||||
if is_torrent
|
|
||||||
&& poll_mgr
|
|
||||||
.is_aria2_control_epoch_current(&id, mapping.epoch)
|
|
||||||
.await
|
|
||||||
{
|
|
||||||
let upload_length = status
|
let upload_length = status
|
||||||
.get("uploadLength")
|
.get("uploadLength")
|
||||||
.and_then(|value| value.as_str())
|
.and_then(|value| value.as_str())
|
||||||
@@ -15557,7 +15841,36 @@ pub fn run() {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
let retry_strike = if !is_torrent {
|
||||||
|
poll_mgr.aria2_retry_strike(&id).await
|
||||||
|
} else {
|
||||||
|
0
|
||||||
|
};
|
||||||
|
let requested_connections = if !is_torrent {
|
||||||
|
poll_mgr
|
||||||
|
.aria2_requested_connections(&id)
|
||||||
|
.await
|
||||||
|
.unwrap_or(1)
|
||||||
|
.max(1)
|
||||||
|
} else {
|
||||||
|
1
|
||||||
|
};
|
||||||
|
let effective_connections = if !is_torrent {
|
||||||
|
poll_mgr
|
||||||
|
.aria2_effective_connections(&id, mapping.epoch)
|
||||||
|
.await
|
||||||
|
.unwrap_or(requested_connections)
|
||||||
|
.max(1)
|
||||||
|
} else {
|
||||||
|
1
|
||||||
|
};
|
||||||
|
if !poll_mgr.is_current_aria2_gid_mapping(&gid, &mapping)
|
||||||
|
|| !poll_mgr
|
||||||
|
.is_aria2_control_epoch_current(&id, mapping.epoch)
|
||||||
|
.await
|
||||||
|
{
|
||||||
|
continue;
|
||||||
|
}
|
||||||
let status_name = status
|
let status_name = status
|
||||||
.get("status")
|
.get("status")
|
||||||
.and_then(|value| value.as_str())
|
.and_then(|value| value.as_str())
|
||||||
@@ -15591,18 +15904,36 @@ pub fn run() {
|
|||||||
_ => None,
|
_ => None,
|
||||||
};
|
};
|
||||||
if let Some(outcome) = outcome {
|
if let Some(outcome) = outcome {
|
||||||
|
let terminal_error = match &outcome {
|
||||||
|
crate::queue::PendingOutcome::Error(error) => Some(error.as_str()),
|
||||||
|
_ => None,
|
||||||
|
};
|
||||||
log::info!(
|
log::info!(
|
||||||
"aria2 poller reconciliation [{}]: gid {} reported terminal status {} outside tellActive",
|
"aria2 poller reconciliation [stage=terminal id={} gid={} epoch={} retry_strike={} status={} requested_connections={} effective_connections={} error_class={} error_code={} source=tell_status_outside_active]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
status_name
|
mapping.epoch,
|
||||||
|
retry_strike,
|
||||||
|
status_name,
|
||||||
|
requested_connections,
|
||||||
|
effective_connections,
|
||||||
|
terminal_error
|
||||||
|
.map(crate::retry::network_error_class)
|
||||||
|
.unwrap_or("none"),
|
||||||
|
terminal_error
|
||||||
|
.and_then(crate::retry::aria2_error_code)
|
||||||
|
.unwrap_or_else(|| "none".to_string())
|
||||||
);
|
);
|
||||||
poll_mgr.handle_aria2_event(&gid, outcome).await;
|
poll_mgr.handle_aria2_event(&gid, outcome).await;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
observations.retain(|id, _| seen_ids.contains(id));
|
observations.retain(|id, _| seen_ids.contains(id));
|
||||||
|
} else {
|
||||||
|
log::warn!(
|
||||||
|
"aria2 poller [stage=poll operation=tell_active result=malformed elapsed_ms={}]",
|
||||||
|
active_poll_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
}
|
}
|
||||||
}
|
|
||||||
}
|
}
|
||||||
});
|
});
|
||||||
|
|
||||||
|
|||||||
+278
-45
@@ -2,8 +2,8 @@ use base64::Engine as _;
|
|||||||
use crate::ipc::{DownloadStateEvent, DownloadStatus, QueueDirection};
|
use crate::ipc::{DownloadStateEvent, DownloadStatus, QueueDirection};
|
||||||
use crate::power::PowerManager;
|
use crate::power::PowerManager;
|
||||||
use crate::retry::{
|
use crate::retry::{
|
||||||
backoff_and_emit, is_aria2_name_resolution_error, is_transient_network_error,
|
aria2_error_code, backoff_and_emit, is_aria2_name_resolution_error,
|
||||||
BackoffOutcome, MAX_RETRIES,
|
is_transient_network_error, network_error_class, BackoffOutcome, MAX_RETRIES,
|
||||||
};
|
};
|
||||||
use log;
|
use log;
|
||||||
use serde::Deserialize;
|
use serde::Deserialize;
|
||||||
@@ -1923,6 +1923,15 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
self.aria2_retry_strikes.lock().await.contains_key(id)
|
self.aria2_retry_strikes.lock().await.contains_key(id)
|
||||||
}
|
}
|
||||||
|
|
||||||
|
pub async fn aria2_retry_strike(&self, id: &str) -> usize {
|
||||||
|
self.aria2_retry_strikes
|
||||||
|
.lock()
|
||||||
|
.await
|
||||||
|
.get(id)
|
||||||
|
.copied()
|
||||||
|
.unwrap_or_default()
|
||||||
|
}
|
||||||
|
|
||||||
pub async fn aria2_requested_connections(&self, id: &str) -> Option<i32> {
|
pub async fn aria2_requested_connections(&self, id: &str) -> Option<i32> {
|
||||||
self.aria2_payloads
|
self.aria2_payloads
|
||||||
.lock()
|
.lock()
|
||||||
@@ -3952,7 +3961,14 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
}
|
}
|
||||||
buffered.remove(&gid).map(|(_buf_id, outcome)| outcome)
|
buffered.remove(&gid).map(|(_buf_id, outcome)| outcome)
|
||||||
};
|
};
|
||||||
log::info!("aria2 gid transition [{}]: mapped {}", id, gid);
|
let retry_strike = self.aria2_retry_strike(&id).await;
|
||||||
|
log::info!(
|
||||||
|
"aria2 gid transition [stage=gid_transition id={} gid={} epoch={} retry_strike={} action=mapped]",
|
||||||
|
id,
|
||||||
|
gid,
|
||||||
|
epoch,
|
||||||
|
retry_strike
|
||||||
|
);
|
||||||
buffered_outcome
|
buffered_outcome
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -4182,16 +4198,17 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
if verification_only {
|
if verification_only {
|
||||||
self.emit_paused_with_error(id, error);
|
self.emit_paused_with_error(id, error);
|
||||||
} else {
|
} else {
|
||||||
let safe_error = crate::redact_sensitive_text(&error);
|
let aria2_code = aria2_error_code(&error).unwrap_or_else(|| "none".to_string());
|
||||||
log::error!(
|
log::error!(
|
||||||
"aria2 terminal [stage=terminal id={} gid={} epoch={} retry_strike={} requested_connections={} effective_connections={} error={}]",
|
"aria2 terminal [stage=terminal id={} gid={} epoch={} retry_strike={} requested_connections={} effective_connections={} error_class={} aria2_error_code={}]",
|
||||||
id,
|
id,
|
||||||
terminal_gid,
|
terminal_gid,
|
||||||
terminal_epoch,
|
terminal_epoch,
|
||||||
retry_strike,
|
retry_strike,
|
||||||
requested_connections,
|
requested_connections,
|
||||||
effective_connections,
|
effective_connections,
|
||||||
safe_error
|
network_error_class(&error),
|
||||||
|
aria2_code
|
||||||
);
|
);
|
||||||
self.emit_failed(id, error);
|
self.emit_failed(id, error);
|
||||||
}
|
}
|
||||||
@@ -4258,21 +4275,23 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
}
|
}
|
||||||
Err(error) if attempt < MAX_ATTEMPTS => {
|
Err(error) if attempt < MAX_ATTEMPTS => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 lifecycle cleanup [{}]: failed to remove stale replacement gid {} on attempt {}: {}; retrying",
|
"aria2 lifecycle cleanup [stage=cleanup id={} gid={} attempt={} result=retrying error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
attempt,
|
attempt,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
tokio::time::sleep(Duration::from_millis(100)).await;
|
tokio::time::sleep(Duration::from_millis(100)).await;
|
||||||
}
|
}
|
||||||
Err(error) => {
|
Err(error) => {
|
||||||
log::error!(
|
log::error!(
|
||||||
"aria2 lifecycle cleanup [{}]: stale replacement gid {} could not be removed after {} attempts: {}",
|
"aria2 lifecycle cleanup [stage=cleanup id={} gid={} attempts={} result=failed error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
MAX_ATTEMPTS,
|
MAX_ATTEMPTS,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -4579,10 +4598,11 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
self.release_permit(id).await;
|
self.release_permit(id).await;
|
||||||
self.emit_state(id, DownloadStatus::Paused);
|
self.emit_state(id, DownloadStatus::Paused);
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 connection recovery [{}]: replacement job unavailable; retired stale gid {} and paused the download: {}",
|
"aria2 connection recovery [stage=recovery id={} gid={} result=paused_unavailable error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
return Ok(());
|
return Ok(());
|
||||||
}
|
}
|
||||||
@@ -4771,6 +4791,37 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
self.aria2_system_resolver_fallback_available(),
|
self.aria2_system_resolver_fallback_available(),
|
||||||
);
|
);
|
||||||
let resolver_fallback = retry_action == Aria2RetryAction::SystemResolverFallback;
|
let resolver_fallback = retry_action == Aria2RetryAction::SystemResolverFallback;
|
||||||
|
let requested_connections = self
|
||||||
|
.aria2_requested_connections(&id)
|
||||||
|
.await
|
||||||
|
.unwrap_or(DOWNLOAD_CONNECTIONS_MIN);
|
||||||
|
let effective_connections = self
|
||||||
|
.aria2_effective_connections(&id, mapping.epoch)
|
||||||
|
.await
|
||||||
|
.unwrap_or(requested_connections);
|
||||||
|
let action = match retry_action {
|
||||||
|
Aria2RetryAction::SystemResolverFallback => "system_resolver_fallback",
|
||||||
|
Aria2RetryAction::OrdinaryRetry => "ordinary_retry",
|
||||||
|
Aria2RetryAction::Terminal => "terminal",
|
||||||
|
};
|
||||||
|
let error_code = aria2_error_code(&error)
|
||||||
|
.unwrap_or_else(|| network_error_class(&error).to_string());
|
||||||
|
log::warn!(
|
||||||
|
"aria2 retry [stage=retry id={} gid={} epoch={} retry_strike={} action={} resolver_mode={} error_class={} error_code={} requested_connections={} effective_connections={}]",
|
||||||
|
id,
|
||||||
|
gid,
|
||||||
|
mapping.epoch,
|
||||||
|
strike,
|
||||||
|
action,
|
||||||
|
match payload.aria2_resolver_mode {
|
||||||
|
Aria2ResolverMode::Automatic => "automatic",
|
||||||
|
Aria2ResolverMode::System => "system",
|
||||||
|
},
|
||||||
|
network_error_class(&error),
|
||||||
|
error_code,
|
||||||
|
requested_connections,
|
||||||
|
effective_connections
|
||||||
|
);
|
||||||
// Switching resolver strategy is a bounded transfer repair, not an
|
// Switching resolver strategy is a bounded transfer repair, not an
|
||||||
// ordinary retry. It must still run when the user configured zero
|
// ordinary retry. It must still run when the user configured zero
|
||||||
// automatic retries, while every later failure follows the normal
|
// automatic retries, while every later failure follows the normal
|
||||||
@@ -4901,10 +4952,11 @@ impl<R: tauri::Runtime> QueueManager<R> {
|
|||||||
drop(control_guard);
|
drop(control_guard);
|
||||||
if let Err(error) = this.spawner.remove_uri(&new_gid).await {
|
if let Err(error) = this.spawner.remove_uri(&new_gid).await {
|
||||||
log::error!(
|
log::error!(
|
||||||
"aria2 retry cancellation [{}]: failed to remove late gid {}: {}",
|
"aria2 retry cancellation [stage=cleanup id={} gid={} result=failed error_class={} error_code={}]",
|
||||||
id_for_task,
|
id_for_task,
|
||||||
new_gid,
|
new_gid,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
} else {
|
} else {
|
||||||
log::info!(
|
log::info!(
|
||||||
@@ -5252,10 +5304,21 @@ enum BoundedRangeSupport {
|
|||||||
Unknown,
|
Unknown,
|
||||||
}
|
}
|
||||||
|
|
||||||
|
impl BoundedRangeSupport {
|
||||||
|
fn as_str(self) -> &'static str {
|
||||||
|
match self {
|
||||||
|
Self::Supported => "supported",
|
||||||
|
Self::Unsupported => "unsupported",
|
||||||
|
Self::Unknown => "unknown",
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
struct HttpTransferProbe {
|
struct HttpTransferProbe {
|
||||||
final_uri: String,
|
final_uri: String,
|
||||||
range_support: BoundedRangeSupport,
|
range_support: BoundedRangeSupport,
|
||||||
credentials_allowed: bool,
|
credentials_allowed: bool,
|
||||||
|
redirect_count: usize,
|
||||||
}
|
}
|
||||||
|
|
||||||
struct PreparedNormalTransfer {
|
struct PreparedNormalTransfer {
|
||||||
@@ -5334,6 +5397,7 @@ fn header_name_has_credential_material(name: &str) -> bool {
|
|||||||
|
|
||||||
async fn prepare_normal_transfer(
|
async fn prepare_normal_transfer(
|
||||||
id: &str,
|
id: &str,
|
||||||
|
epoch: u64,
|
||||||
payload: &SpawnPayload,
|
payload: &SpawnPayload,
|
||||||
) -> Result<PreparedNormalTransfer, String> {
|
) -> Result<PreparedNormalTransfer, String> {
|
||||||
let credential_origin = reqwest::Url::parse(&payload.url)
|
let credential_origin = reqwest::Url::parse(&payload.url)
|
||||||
@@ -5366,6 +5430,7 @@ async fn prepare_normal_transfer(
|
|||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
let probe_started = Instant::now();
|
||||||
match probe_bounded_range_support(&uri, payload, &credential_origin).await {
|
match probe_bounded_range_support(&uri, payload, &credential_origin).await {
|
||||||
Ok(probe) => {
|
Ok(probe) => {
|
||||||
if index > 0
|
if index > 0
|
||||||
@@ -5379,19 +5444,37 @@ async fn prepare_normal_transfer(
|
|||||||
}
|
}
|
||||||
credentials_allowed &= probe.credentials_allowed;
|
credentials_allowed &= probe.credentials_allowed;
|
||||||
uris.push(probe.final_uri);
|
uris.push(probe.final_uri);
|
||||||
|
log::info!(
|
||||||
|
"aria2 range probe [stage=range_probe id={} epoch={} host={} support={} redirect_count={} credentials_allowed={} requested_connections={} effective_connections={} elapsed_ms={}]",
|
||||||
|
id,
|
||||||
|
epoch,
|
||||||
|
uri_host_for_log(&uri),
|
||||||
|
probe.range_support.as_str(),
|
||||||
|
probe.redirect_count,
|
||||||
|
probe.credentials_allowed,
|
||||||
|
requested,
|
||||||
|
if probe.range_support == BoundedRangeSupport::Unsupported && requested > 1 {
|
||||||
|
1
|
||||||
|
} else {
|
||||||
|
connections
|
||||||
|
},
|
||||||
|
probe_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
match probe.range_support {
|
match probe.range_support {
|
||||||
BoundedRangeSupport::Unsupported if requested > 1 => {
|
BoundedRangeSupport::Unsupported if requested > 1 => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 range probe [{}]: {} does not honor bounded byte ranges; using one connection",
|
"aria2 range probe [stage=range_probe id={} epoch={} host={} result=unsupported action=single_connection]",
|
||||||
id,
|
id,
|
||||||
|
epoch,
|
||||||
uri_host_for_log(&uri)
|
uri_host_for_log(&uri)
|
||||||
);
|
);
|
||||||
connections = 1;
|
connections = 1;
|
||||||
}
|
}
|
||||||
BoundedRangeSupport::Unknown if requested > 1 => {
|
BoundedRangeSupport::Unknown if requested > 1 => {
|
||||||
log::debug!(
|
log::debug!(
|
||||||
"aria2 range probe [{}]: {} range support unknown; keeping {} connections",
|
"aria2 range probe [stage=range_probe id={} epoch={} host={} result=unknown action=keep_requested connections={}]",
|
||||||
id,
|
id,
|
||||||
|
epoch,
|
||||||
uri_host_for_log(&uri),
|
uri_host_for_log(&uri),
|
||||||
requested
|
requested
|
||||||
);
|
);
|
||||||
@@ -5400,11 +5483,15 @@ async fn prepare_normal_transfer(
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
Err(error) if is_fatal_range_probe_error(&error) => {
|
Err(error) if is_fatal_range_probe_error(&error) => {
|
||||||
log::error!(
|
log::error!(
|
||||||
"aria2 redirect [{}]: fatal transfer validation failed host={} error_code={}",
|
"aria2 redirect [stage=redirect id={} epoch={} host={} result=rejected error_code={} requested_connections={} effective_connections={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
|
epoch,
|
||||||
uri_host_for_log(&uri),
|
uri_host_for_log(&uri),
|
||||||
range_probe_error_code(&error)
|
range_probe_error_code(&error),
|
||||||
|
requested,
|
||||||
|
connections,
|
||||||
|
probe_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"normal transfer preflight rejected for {}: {}",
|
"normal transfer preflight rejected for {}: {}",
|
||||||
@@ -5414,10 +5501,14 @@ async fn prepare_normal_transfer(
|
|||||||
}
|
}
|
||||||
Err(error) if payload_has_credential_material(payload) => {
|
Err(error) if payload_has_credential_material(payload) => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 range probe [{}]: credentialed route could not be verified host={} error_code={}; retryable",
|
"aria2 range probe [stage=range_probe id={} epoch={} host={} result=retryable error_code={} credentials_verified=false requested_connections={} effective_connections={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
|
epoch,
|
||||||
uri_host_for_log(&uri),
|
uri_host_for_log(&uri),
|
||||||
range_probe_error_code(&error)
|
range_probe_error_code(&error),
|
||||||
|
requested,
|
||||||
|
connections,
|
||||||
|
probe_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
return Err(format!(
|
return Err(format!(
|
||||||
"normal transfer preflight is retryable for {}: {}",
|
"normal transfer preflight is retryable for {}: {}",
|
||||||
@@ -5427,10 +5518,14 @@ async fn prepare_normal_transfer(
|
|||||||
}
|
}
|
||||||
Err(error) => {
|
Err(error) => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 range probe [{}]: public route unavailable host={} error_code={}; trying the validated source URI",
|
"aria2 range probe [stage=range_probe id={} epoch={} host={} result=unknown action=use_source_uri error_code={} credentials_verified=false requested_connections={} effective_connections={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
|
epoch,
|
||||||
uri_host_for_log(&uri),
|
uri_host_for_log(&uri),
|
||||||
range_probe_error_code(&error)
|
range_probe_error_code(&error),
|
||||||
|
requested,
|
||||||
|
connections,
|
||||||
|
probe_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
uris.push(uri);
|
uris.push(uri);
|
||||||
}
|
}
|
||||||
@@ -5480,10 +5575,29 @@ fn range_probe_error_code(error: &str) -> &'static str {
|
|||||||
} else if lower.contains("invalid") {
|
} else if lower.contains("invalid") {
|
||||||
"invalid_route"
|
"invalid_route"
|
||||||
} else {
|
} else {
|
||||||
"transport"
|
match network_error_class(error) {
|
||||||
|
"name_resolution" | "dns" => "dns",
|
||||||
|
"ssrf_policy" => "ssrf_private_address",
|
||||||
|
class => class,
|
||||||
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
fn transfer_preflight_error_code(error: &str) -> &'static str {
|
||||||
|
if error
|
||||||
|
.to_ascii_lowercase()
|
||||||
|
.contains("credentialed mirrors must use the same origin")
|
||||||
|
{
|
||||||
|
"credential_policy"
|
||||||
|
} else {
|
||||||
|
range_probe_error_code(error)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
fn diagnostic_error_code(error: &str) -> String {
|
||||||
|
aria2_error_code(error).unwrap_or_else(|| network_error_class(error).to_string())
|
||||||
|
}
|
||||||
|
|
||||||
fn is_http_uri(uri: &str) -> bool {
|
fn is_http_uri(uri: &str) -> bool {
|
||||||
reqwest::Url::parse(uri)
|
reqwest::Url::parse(uri)
|
||||||
.ok()
|
.ok()
|
||||||
@@ -5519,6 +5633,14 @@ pub(crate) fn aria2_all_proxy_value(proxy: &str) -> Result<Option<String>, Strin
|
|||||||
Ok(Some(proxy.to_string()))
|
Ok(Some(proxy.to_string()))
|
||||||
}
|
}
|
||||||
|
|
||||||
|
pub(crate) fn proxy_route_for_log(proxy: Option<&str>) -> &'static str {
|
||||||
|
match proxy.map(str::trim) {
|
||||||
|
None | Some("") => "none",
|
||||||
|
Some(value) if value.eq_ignore_ascii_case("none") => "disabled",
|
||||||
|
Some(_) => "configured",
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
async fn probe_bounded_range_support(
|
async fn probe_bounded_range_support(
|
||||||
uri: &str,
|
uri: &str,
|
||||||
payload: &SpawnPayload,
|
payload: &SpawnPayload,
|
||||||
@@ -5630,6 +5752,7 @@ async fn probe_bounded_range_support_with_local_override(
|
|||||||
final_uri: current.to_string(),
|
final_uri: current.to_string(),
|
||||||
range_support: classify_bounded_range_response(response.status(), content_range),
|
range_support: classify_bounded_range_response(response.status(), content_range),
|
||||||
credentials_allowed,
|
credentials_allowed,
|
||||||
|
redirect_count,
|
||||||
});
|
});
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -5763,17 +5886,35 @@ fn apply_checksum_options(
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
async fn validate_aria2_transfer_network_policy(uris: &[String]) -> Result<(), String> {
|
struct Aria2NetworkPolicyError {
|
||||||
|
host: String,
|
||||||
|
message: String,
|
||||||
|
}
|
||||||
|
|
||||||
|
async fn validate_aria2_transfer_network_policy(
|
||||||
|
uris: &[String],
|
||||||
|
) -> Result<(), Aria2NetworkPolicyError> {
|
||||||
for uri in uris {
|
for uri in uris {
|
||||||
let parsed = reqwest::Url::parse(uri).map_err(|_| "SSRF blocked: Invalid URL".to_string())?;
|
let parsed = reqwest::Url::parse(uri).map_err(|_| Aria2NetworkPolicyError {
|
||||||
|
host: uri_host_for_log(uri),
|
||||||
|
message: "SSRF blocked: Invalid URL".to_string(),
|
||||||
|
})?;
|
||||||
if !matches!(parsed.scheme(), "http" | "https" | "ftp" | "sftp") {
|
if !matches!(parsed.scheme(), "http" | "https" | "ftp" | "sftp") {
|
||||||
return Err("Unsupported URL scheme".to_string());
|
return Err(Aria2NetworkPolicyError {
|
||||||
|
host: uri_host_for_log(uri),
|
||||||
|
message: "Unsupported URL scheme".to_string(),
|
||||||
|
});
|
||||||
}
|
}
|
||||||
// This is deliberately repeated immediately before addUri/addTorrent
|
// This is deliberately repeated immediately before addUri/addTorrent
|
||||||
// so admission-time DNS is not the only policy check. Aria2 still
|
// so admission-time DNS is not the only policy check. Aria2 still
|
||||||
// resolves independently later; Firelink therefore does not claim
|
// resolves independently later; Firelink therefore does not claim
|
||||||
// that this is an IP pinning boundary.
|
// that this is an IP pinning boundary.
|
||||||
crate::resolve_and_validate_url_host(&parsed).await?;
|
if let Err(error) = crate::resolve_and_validate_url_host(&parsed).await {
|
||||||
|
return Err(Aria2NetworkPolicyError {
|
||||||
|
host: uri_host_for_log(uri),
|
||||||
|
message: error,
|
||||||
|
});
|
||||||
|
}
|
||||||
}
|
}
|
||||||
Ok(())
|
Ok(())
|
||||||
}
|
}
|
||||||
@@ -6887,6 +7028,7 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
async fn add_uri(&self, id: &str, payload: &SpawnPayload) -> Result<String, String> {
|
async fn add_uri(&self, id: &str, payload: &SpawnPayload) -> Result<String, String> {
|
||||||
let state = self.app_handle.state::<crate::AppState>();
|
let state = self.app_handle.state::<crate::AppState>();
|
||||||
let attempt_epoch = state.queue_manager.current_aria2_control_epoch(id).await;
|
let attempt_epoch = state.queue_manager.current_aria2_control_epoch(id).await;
|
||||||
|
let admission_started = Instant::now();
|
||||||
let mut options = serde_json::Map::new();
|
let mut options = serde_json::Map::new();
|
||||||
let mut connection_options = None;
|
let mut connection_options = None;
|
||||||
let resolved_dest = crate::resolve_path(&payload.destination, &self.app_handle);
|
let resolved_dest = crate::resolve_path(&payload.destination, &self.app_handle);
|
||||||
@@ -6915,10 +7057,45 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
if payload.is_torrent {
|
if payload.is_torrent {
|
||||||
(Vec::new(), DOWNLOAD_CONNECTIONS_MIN, DOWNLOAD_CONNECTIONS_MIN, true)
|
(Vec::new(), DOWNLOAD_CONNECTIONS_MIN, DOWNLOAD_CONNECTIONS_MIN, true)
|
||||||
} else {
|
} else {
|
||||||
let requested =
|
let requested_uris =
|
||||||
crate::collect_download_uris(&payload.url, payload.mirrors.as_deref());
|
crate::collect_download_uris(&payload.url, payload.mirrors.as_deref());
|
||||||
validate_aria2_transfer_network_policy(&requested).await?;
|
let requested_connections =
|
||||||
let prepared = prepare_normal_transfer(id, payload).await?;
|
clamp_download_connections(payload.connections.unwrap_or(DOWNLOAD_CONNECTIONS_MIN));
|
||||||
|
if let Err(error) = validate_aria2_transfer_network_policy(&requested_uris).await {
|
||||||
|
log::error!(
|
||||||
|
"aria2 admission [stage=network_policy id={} epoch={} host={} proxy_route={} uri_count={} requested_connections={} effective_connections=not_established error_class={} error_code={} elapsed_ms={}]",
|
||||||
|
id,
|
||||||
|
attempt_epoch,
|
||||||
|
error.host,
|
||||||
|
proxy_route_for_log(payload.proxy.as_deref()),
|
||||||
|
requested_uris.len(),
|
||||||
|
requested_connections,
|
||||||
|
network_error_class(&error.message),
|
||||||
|
transfer_preflight_error_code(&error.message),
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(error.message);
|
||||||
|
}
|
||||||
|
let prepared = match prepare_normal_transfer(id, attempt_epoch, payload).await {
|
||||||
|
Ok(prepared) => prepared,
|
||||||
|
Err(error) => {
|
||||||
|
log::error!(
|
||||||
|
"aria2 admission [stage=transfer_preflight id={} epoch={} host={} proxy_route={} requested_connections={} effective_connections=not_established error_class={} error_code={} elapsed_ms={}]",
|
||||||
|
id,
|
||||||
|
attempt_epoch,
|
||||||
|
requested_uris
|
||||||
|
.first()
|
||||||
|
.map(|uri| uri_host_for_log(uri))
|
||||||
|
.unwrap_or_else(|| "<unknown host>".to_string()),
|
||||||
|
proxy_route_for_log(payload.proxy.as_deref()),
|
||||||
|
requested_connections,
|
||||||
|
network_error_class(&error),
|
||||||
|
transfer_preflight_error_code(&error),
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err(error);
|
||||||
|
}
|
||||||
|
};
|
||||||
connection_options = Some(prepared.effective_connections);
|
connection_options = Some(prepared.effective_connections);
|
||||||
(
|
(
|
||||||
prepared.uris,
|
prepared.uris,
|
||||||
@@ -6977,18 +7154,27 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
options.insert("all-proxy".to_string(), serde_json::json!(prox));
|
options.insert("all-proxy".to_string(), serde_json::json!(prox));
|
||||||
}
|
}
|
||||||
apply_aria2_resolver_options(&mut options, payload.aria2_resolver_mode);
|
apply_aria2_resolver_options(&mut options, payload.aria2_resolver_mode);
|
||||||
|
let retry_strike = state.queue_manager.aria2_retry_strike(id).await;
|
||||||
|
let transfer_host = transfer_uris
|
||||||
|
.first()
|
||||||
|
.map(|uri| uri_host_for_log(uri))
|
||||||
|
.unwrap_or_else(|| "<torrent>".to_string());
|
||||||
|
|
||||||
log::info!(
|
log::info!(
|
||||||
"aria2 admission [stage=admission id={} epoch={} host={} requested_connections={} effective_connections={} uri_count={}]",
|
"aria2 admission [stage=admission id={} epoch={} retry_strike={} host={} requested_connections={} effective_connections={} uri_count={} resolver_mode={} proxy_route={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
attempt_epoch,
|
attempt_epoch,
|
||||||
transfer_uris
|
retry_strike,
|
||||||
.first()
|
transfer_host,
|
||||||
.map(|uri| uri_host_for_log(uri))
|
|
||||||
.unwrap_or_else(|| "<torrent>".to_string()),
|
|
||||||
requested_connections,
|
requested_connections,
|
||||||
transfer_connections,
|
transfer_connections,
|
||||||
transfer_uris.len()
|
transfer_uris.len(),
|
||||||
|
match payload.aria2_resolver_mode {
|
||||||
|
Aria2ResolverMode::Automatic => "automatic",
|
||||||
|
Aria2ResolverMode::System => "system",
|
||||||
|
},
|
||||||
|
proxy_route_for_log(payload.proxy.as_deref()),
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
|
|
||||||
let (method, params) = if payload.is_torrent {
|
let (method, params) = if payload.is_torrent {
|
||||||
@@ -7057,6 +7243,25 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
)
|
)
|
||||||
};
|
};
|
||||||
|
|
||||||
|
let lifecycle_current = state
|
||||||
|
.queue_manager
|
||||||
|
.is_aria2_control_epoch_current(id, attempt_epoch)
|
||||||
|
.await
|
||||||
|
&& state.queue_manager.is_registered(id).await;
|
||||||
|
if !lifecycle_current {
|
||||||
|
log::info!(
|
||||||
|
"aria2 admission [stage=admission id={} epoch={} retry_strike={} host={} requested_connections={} effective_connections={} result=stale_before_rpc elapsed_ms={}]",
|
||||||
|
id,
|
||||||
|
attempt_epoch,
|
||||||
|
retry_strike,
|
||||||
|
transfer_host,
|
||||||
|
requested_connections,
|
||||||
|
transfer_connections,
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
|
return Err("aria2 admission canceled before RPC".to_string());
|
||||||
|
}
|
||||||
|
|
||||||
match self.add_transfer_rpc(&state, method, ¶ms).await {
|
match self.add_transfer_rpc(&state, method, ¶ms).await {
|
||||||
Ok(result) => {
|
Ok(result) => {
|
||||||
let gid = result.as_str().unwrap_or("").to_string();
|
let gid = result.as_str().unwrap_or("").to_string();
|
||||||
@@ -7073,19 +7278,31 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
)
|
)
|
||||||
.await;
|
.await;
|
||||||
}
|
}
|
||||||
log::info!("aria2 {} [{}]: created gid {}", method, id, gid);
|
log::info!(
|
||||||
|
"aria2 {} [stage=admission id={} gid={} epoch={} retry_strike={} elapsed_ms={} result=created]",
|
||||||
|
method,
|
||||||
|
id,
|
||||||
|
gid,
|
||||||
|
attempt_epoch,
|
||||||
|
retry_strike,
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
|
);
|
||||||
Ok(gid)
|
Ok(gid)
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
Err(e) => {
|
Err(e) => {
|
||||||
let safe_error = crate::redact_sensitive_text(&e);
|
let error_code = aria2_error_code(&e)
|
||||||
|
.unwrap_or_else(|| network_error_class(&e).to_string());
|
||||||
log::error!(
|
log::error!(
|
||||||
"aria2 admission [stage=admission id={} epoch={} method={} error={}]",
|
"aria2 admission [stage=admission id={} epoch={} method={} error_class={} error_code={} elapsed_ms={}]",
|
||||||
id,
|
id,
|
||||||
attempt_epoch,
|
attempt_epoch,
|
||||||
method,
|
method,
|
||||||
safe_error
|
network_error_class(&e),
|
||||||
|
error_code,
|
||||||
|
admission_started.elapsed().as_millis()
|
||||||
);
|
);
|
||||||
|
let safe_error = crate::redact_sensitive_text(&e);
|
||||||
Err(format!("aria2 {method} failed: {safe_error}"))
|
Err(format!("aria2 {method} failed: {safe_error}"))
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -7279,10 +7496,11 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
match crate::aria2_download_status(port, secret, gid).await {
|
match crate::aria2_download_status(port, secret, gid).await {
|
||||||
Ok(status) if status == "paused" => {
|
Ok(status) if status == "paused" => {
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 connection recovery [{}]: forcePause for gid {} returned an error after the daemon paused it: {}",
|
"aria2 connection recovery [stage=recovery id={} gid={} operation=force_pause result=verified_paused error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
Ok(status) if status == "complete" => {
|
Ok(status) if status == "complete" => {
|
||||||
@@ -7292,10 +7510,11 @@ impl SidecarSpawner for ProductionSpawner {
|
|||||||
if aria2_recovery_should_rebuild_after_pause_error(&status) =>
|
if aria2_recovery_should_rebuild_after_pause_error(&status) =>
|
||||||
{
|
{
|
||||||
log::warn!(
|
log::warn!(
|
||||||
"aria2 connection recovery [{}]: gid {} disappeared after forcePause failed; rebuilding from the saved payload: {}",
|
"aria2 connection recovery [stage=recovery id={} gid={} operation=force_pause result=gid_missing_rebuild error_class={} error_code={}]",
|
||||||
id,
|
id,
|
||||||
gid,
|
gid,
|
||||||
error
|
network_error_class(&error),
|
||||||
|
diagnostic_error_code(&error)
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
Ok(status) => {
|
Ok(status) => {
|
||||||
@@ -9118,6 +9337,10 @@ mod tests {
|
|||||||
fn public_probe_transport_failures_are_advisory_but_security_failures_are_fatal() {
|
fn public_probe_transport_failures_are_advisory_but_security_failures_are_fatal() {
|
||||||
assert!(!is_fatal_range_probe_error("error sending request"));
|
assert!(!is_fatal_range_probe_error("error sending request"));
|
||||||
assert_eq!(range_probe_error_code("error sending request"), "transport");
|
assert_eq!(range_probe_error_code("error sending request"), "transport");
|
||||||
|
assert_eq!(
|
||||||
|
range_probe_error_code("error sending request for https://example.test/file"),
|
||||||
|
"transport"
|
||||||
|
);
|
||||||
assert!(is_fatal_range_probe_error("SSRF blocked: Private/local IP not allowed"));
|
assert!(is_fatal_range_probe_error("SSRF blocked: Private/local IP not allowed"));
|
||||||
assert_eq!(
|
assert_eq!(
|
||||||
range_probe_error_code("SSRF blocked: DNS resolution timed out"),
|
range_probe_error_code("SSRF blocked: DNS resolution timed out"),
|
||||||
@@ -9125,6 +9348,16 @@ mod tests {
|
|||||||
);
|
);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn proxy_route_diagnostics_never_include_proxy_details() {
|
||||||
|
assert_eq!(proxy_route_for_log(None), "none");
|
||||||
|
assert_eq!(proxy_route_for_log(Some("none")), "disabled");
|
||||||
|
assert_eq!(
|
||||||
|
proxy_route_for_log(Some("http://user:secret@example.test:8080")),
|
||||||
|
"configured"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
#[test]
|
#[test]
|
||||||
fn enqueue_item_carries_torrent_trackers_into_the_spawn_payload() {
|
fn enqueue_item_carries_torrent_trackers_into_the_spawn_payload() {
|
||||||
let item: EnqueueItem = serde_json::from_value(serde_json::json!({
|
let item: EnqueueItem = serde_json::from_value(serde_json::json!({
|
||||||
|
|||||||
+142
-1
@@ -55,13 +55,116 @@ pub const MAX_RETRIES: usize = BACKOFF_SCHEDULE.len();
|
|||||||
/// the message forms cover older/alternate Aria2 wrappers that omit it.
|
/// the message forms cover older/alternate Aria2 wrappers that omit it.
|
||||||
pub fn is_aria2_name_resolution_error(message: &str) -> bool {
|
pub fn is_aria2_name_resolution_error(message: &str) -> bool {
|
||||||
let lower = message.to_ascii_lowercase();
|
let lower = message.to_ascii_lowercase();
|
||||||
lower.contains("aria2 error code 19")
|
aria2_error_code(message).as_deref() == Some("19")
|
||||||
|| (lower.contains("name resolution")
|
|| (lower.contains("name resolution")
|
||||||
&& lower.contains("failed")
|
&& lower.contains("failed")
|
||||||
&& lower.contains("could not contact dns"))
|
&& lower.contains("could not contact dns"))
|
||||||
|| lower.contains("could not contact dns server")
|
|| lower.contains("could not contact dns server")
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Extract Aria2's numeric error code without retaining the rest of its
|
||||||
|
/// message. Aria2 error messages can include the request URI, so diagnostics
|
||||||
|
/// should record this code rather than the raw text.
|
||||||
|
pub fn aria2_error_code(message: &str) -> Option<String> {
|
||||||
|
let lower = message.to_ascii_lowercase();
|
||||||
|
let marker = "aria2 error code";
|
||||||
|
let start = lower.find(marker)? + marker.len();
|
||||||
|
let remainder = lower[start..].trim_start_matches(|character: char| {
|
||||||
|
character.is_ascii_whitespace()
|
||||||
|
|| matches!(character, ':' | '=' | '(' | ')' | '[' | ']')
|
||||||
|
});
|
||||||
|
let digits: String = remainder
|
||||||
|
.chars()
|
||||||
|
.take_while(|character| character.is_ascii_digit())
|
||||||
|
.collect();
|
||||||
|
(!digits.is_empty()).then_some(digits)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Coarse, secret-free classification for retry diagnostics. The returned
|
||||||
|
/// value is intentionally stable and contains no provider or request text.
|
||||||
|
pub fn network_error_class(message: &str) -> &'static str {
|
||||||
|
if is_aria2_name_resolution_error(message) {
|
||||||
|
return "name_resolution";
|
||||||
|
}
|
||||||
|
let lower = message.to_ascii_lowercase();
|
||||||
|
if lower.contains("private/local ip") || lower.contains("ssrf") {
|
||||||
|
return "ssrf_policy";
|
||||||
|
}
|
||||||
|
if lower.contains("permission denied") || lower.contains("operation not permitted") {
|
||||||
|
return "permission";
|
||||||
|
}
|
||||||
|
if lower.contains("timed out") || lower.contains("timeout") {
|
||||||
|
return "timeout";
|
||||||
|
}
|
||||||
|
if lower.contains("connection refused") {
|
||||||
|
return "connection_refused";
|
||||||
|
}
|
||||||
|
if lower.contains("connection reset") || lower.contains("connection aborted") {
|
||||||
|
return "connection_reset";
|
||||||
|
}
|
||||||
|
if [
|
||||||
|
"invalid range",
|
||||||
|
"range not satisfiable",
|
||||||
|
"range request",
|
||||||
|
"range support",
|
||||||
|
"accept-ranges",
|
||||||
|
"bounded range",
|
||||||
|
"byte range",
|
||||||
|
"does not support range",
|
||||||
|
]
|
||||||
|
.iter()
|
||||||
|
.any(|marker| lower.contains(marker))
|
||||||
|
{
|
||||||
|
return "range";
|
||||||
|
}
|
||||||
|
if lower.contains("dns") || lower.contains("name resolution") {
|
||||||
|
return "dns";
|
||||||
|
}
|
||||||
|
let has_http_version_token = lower.split_whitespace().any(|token| {
|
||||||
|
let token = token.trim_start_matches(|character: char| {
|
||||||
|
matches!(character, '(' | '[' | '{')
|
||||||
|
});
|
||||||
|
token.starts_with("http/")
|
||||||
|
&& token
|
||||||
|
.chars()
|
||||||
|
.nth(5)
|
||||||
|
.is_some_and(|character| character.is_ascii_digit())
|
||||||
|
});
|
||||||
|
if lower.contains("http error")
|
||||||
|
|| has_http_version_token
|
||||||
|
|| lower.contains("http status")
|
||||||
|
|| lower.contains("response status")
|
||||||
|
|| lower.contains("status code")
|
||||||
|
|| [
|
||||||
|
"status=400",
|
||||||
|
"status=401",
|
||||||
|
"status=403",
|
||||||
|
"status=404",
|
||||||
|
"status=408",
|
||||||
|
"status=410",
|
||||||
|
"status=429",
|
||||||
|
"status=451",
|
||||||
|
"status=500",
|
||||||
|
"status=502",
|
||||||
|
"status=503",
|
||||||
|
"status=504",
|
||||||
|
]
|
||||||
|
.iter()
|
||||||
|
.any(|marker| {
|
||||||
|
lower.split_whitespace().any(|token| {
|
||||||
|
token
|
||||||
|
.trim_matches(|character: char| {
|
||||||
|
!character.is_ascii_alphanumeric() && character != '='
|
||||||
|
})
|
||||||
|
== *marker
|
||||||
|
})
|
||||||
|
})
|
||||||
|
{
|
||||||
|
return "http";
|
||||||
|
}
|
||||||
|
"transport"
|
||||||
|
}
|
||||||
|
|
||||||
/// Resolve the backoff delay for a 0-based strike. Strikes at or beyond the
|
/// Resolve the backoff delay for a 0-based strike. Strikes at or beyond the
|
||||||
/// schedule length clamp to the longest slot (10s) rather than panicking, so a
|
/// schedule length clamp to the longest slot (10s) rather than panicking, so a
|
||||||
/// mis-sized loop degrades gracefully instead of aborting the worker.
|
/// mis-sized loop degrades gracefully instead of aborting the worker.
|
||||||
@@ -263,6 +366,44 @@ mod tests {
|
|||||||
assert_eq!(MAX_RETRIES, 3);
|
assert_eq!(MAX_RETRIES, 3);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn extracts_aria2_error_code_without_message_material() {
|
||||||
|
for error in [
|
||||||
|
"aria2 error code 19: Could not contact DNS servers",
|
||||||
|
"aria2 error code: 19: Could not contact DNS servers",
|
||||||
|
"aria2 error code (19): Could not contact DNS servers",
|
||||||
|
"aria2 error code=19: Could not contact DNS servers",
|
||||||
|
] {
|
||||||
|
assert_eq!(aria2_error_code(error).as_deref(), Some("19"));
|
||||||
|
}
|
||||||
|
let error =
|
||||||
|
"aria2 error code 19: Could not contact DNS servers for https://example.test/file?token=secret";
|
||||||
|
assert_eq!(network_error_class(error), "name_resolution");
|
||||||
|
assert_eq!(aria2_error_code("aria2 error code: unknown 19"), None);
|
||||||
|
assert!(is_aria2_name_resolution_error("aria2 error code: 19"));
|
||||||
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn classifies_diagnostic_errors_without_echoing_private_details() {
|
||||||
|
assert_eq!(network_error_class("operation not permitted"), "permission");
|
||||||
|
assert_eq!(network_error_class("connect timed out"), "timeout");
|
||||||
|
assert_eq!(network_error_class("invalid range header"), "range");
|
||||||
|
assert_eq!(
|
||||||
|
network_error_class("error sending request for https://example.test/file"),
|
||||||
|
"transport"
|
||||||
|
);
|
||||||
|
assert_eq!(
|
||||||
|
network_error_class("error sending request for http://example.test/file"),
|
||||||
|
"transport"
|
||||||
|
);
|
||||||
|
assert_eq!(
|
||||||
|
network_error_class("error sending request for https://example.test/file?status=503"),
|
||||||
|
"transport"
|
||||||
|
);
|
||||||
|
assert_eq!(network_error_class("ranged GET fallback failed"), "transport");
|
||||||
|
assert_eq!(network_error_class("HTTP Error 503"), "http");
|
||||||
|
}
|
||||||
|
|
||||||
#[test]
|
#[test]
|
||||||
fn backoff_for_indexes_then_clamps() {
|
fn backoff_for_indexes_then_clamps() {
|
||||||
assert_eq!(backoff_for(0), Duration::from_secs(2));
|
assert_eq!(backoff_for(0), Duration::from_secs(2));
|
||||||
|
|||||||
Reference in New Issue
Block a user