diff --git a/src/common.rs b/src/common.rs index bf8964a55..23aa489a5 100644 --- a/src/common.rs +++ b/src/common.rs @@ -59,6 +59,7 @@ pub const PLATFORM_MACOS: &str = "Mac OS"; pub const PLATFORM_ANDROID: &str = "Android"; pub const TIMER_OUT: Duration = Duration::from_secs(1); +pub(crate) const API_LOG_INTERVAL: Duration = Duration::from_secs(600); pub const DEFAULT_KEEP_ALIVE: i32 = 60_000; const MIN_VER_MULTI_UI_SESSION: &str = "1.2.4"; @@ -1244,6 +1245,23 @@ fn is_tcp_proxy_api_target(url: &str) -> bool { should_use_tcp_proxy_for_api_url(url, &ui_get_api_server()) } +#[inline] +fn should_throttle_log(url: &str) -> bool { + url::Url::parse(url) + .map(|parsed| parsed.path().ends_with("/api/heartbeat")) + .unwrap_or(false) +} + +macro_rules! api_log { + ($level:ident, $url:expr, $interval:expr, $($arg:tt)+) => {{ + if should_throttle_log($url) { + hbb_common::throttled_log!($interval, $level, $($arg)+); + } else { + log::$level!($($arg)+); + } + }}; +} + fn tcp_proxy_log_target(url: &str) -> String { url::Url::parse(url) .ok() @@ -1293,7 +1311,10 @@ async fn tcp_proxy_request( parsed.path().to_string() }; - log::debug!( + api_log!( + debug, + url, + API_LOG_INTERVAL, "Sending {} {} via TCP proxy to {}", method, parsed.path(), @@ -1453,7 +1474,10 @@ where }; if should_fallback && can_fallback_to_raw_tcp(url) { - log::warn!( + api_log!( + warn, + url, + API_LOG_INTERVAL, "HTTP {} to {} failed or 5xx (result: {:?}), trying TCP proxy fallback", method, tcp_proxy_log_target(url), @@ -1465,7 +1489,13 @@ where match tcp_fn.await { Ok(resp) => return Ok(resp), Err(tcp_err) => { - log::warn!("TCP proxy fallback also failed: {:?}", tcp_err); + api_log!( + warn, + url, + API_LOG_INTERVAL, + "TCP proxy fallback also failed: {:?}", + tcp_err + ); } } } @@ -1523,7 +1553,10 @@ pub async fn post_request_with_status( Ok((status, _)) => *status >= 500, }; if should_fallback && can_fallback_to_raw_tcp(&url) { - log::warn!( + api_log!( + warn, + &url, + API_LOG_INTERVAL, "HTTP POST to {} failed or 5xx (result: {:?}), trying TCP proxy fallback", tcp_proxy_log_target(&url), http_result @@ -1534,7 +1567,13 @@ pub async fn post_request_with_status( match post_request_via_tcp_proxy_status(&url, &body, header).await { Ok(resp) => return Ok(resp), Err(tcp_err) => { - log::warn!("TCP proxy fallback also failed: {:?}", tcp_err); + api_log!( + warn, + &url, + API_LOG_INTERVAL, + "TCP proxy fallback also failed: {:?}", + tcp_err + ); } } } @@ -1591,7 +1630,10 @@ async fn post_request_( Err(e) => { if (tls_type.is_none() || danger_accept_invalid_cert.is_none()) && e.is_request() { if danger_accept_invalid_cert.is_none() { - log::warn!( + api_log!( + warn, + url, + API_LOG_INTERVAL, "HTTP request failed: {:?}, try again, danger accept invalid cert", e ); @@ -1606,7 +1648,13 @@ async fn post_request_( ) .await } else { - log::warn!("HTTP request failed: {:?}, try again with native-tls", e); + api_log!( + warn, + url, + API_LOG_INTERVAL, + "HTTP request failed: {:?}, try again with native-tls", + e + ); post_request_( url, tls_url, @@ -3104,6 +3152,21 @@ mod tests { )); } + #[test] + fn test_should_throttle_log() { + assert!(should_throttle_log("https://example.com/api/heartbeat")); + assert!(should_throttle_log( + "https://example.com/api/heartbeat?token=secret" + )); + assert!(should_throttle_log("https://example.com/prefix/api/heartbeat")); + assert!(!should_throttle_log("https://example.com/api/heartbeat2")); + assert!(!should_throttle_log("https://example.com/api/sysinfo")); + assert!(!should_throttle_log( + "https://example.com/api/sysinfo?next=/api/heartbeat" + )); + assert!(!should_throttle_log("not a url")); + } + #[test] fn test_get_tcp_proxy_addr_normalizes_bare_ipv6_host() { struct RestoreCustomRendezvousServer(String); diff --git a/src/hbbs_http/sync.rs b/src/hbbs_http/sync.rs index 29e34b745..728e1e8be 100644 --- a/src/hbbs_http/sync.rs +++ b/src/hbbs_http/sync.rs @@ -5,7 +5,7 @@ use std::{ }; #[cfg(not(any(target_os = "ios")))] -use crate::{ui_interface::get_builtin_option, Connection}; +use crate::{common::API_LOG_INTERVAL, ui_interface::get_builtin_option, Connection}; use hbb_common::{ config::{self, Config, LocalConfig}, log, @@ -242,7 +242,11 @@ async fn start_hbbs_sync_async() { } let modified_at = LocalConfig::get_option("strategy_timestamp").parse::().unwrap_or(0); v["modified_at"] = json!(modified_at); - if let Ok(s) = crate::post_request(url.clone(), v.to_string(), "").await { + let response = crate::post_request(url.clone(), v.to_string(), "").await; + if let Err(err) = &response { + hbb_common::throttled_log!(API_LOG_INTERVAL, warn, "Heartbeat failed: {err:?}"); + } + if let Ok(s) = response { if let Ok(mut rsp) = serde_json::from_str::>(&s) { if rsp.remove("sysinfo").is_some() { info_uploaded.uploaded = false;