YoursFunny/TelegramTwitterMediaBot
1
0
Fork 0
mirror of https://github.com/TheFunny/TelegramTwitterMediaBot.git synced 2026-09-23 23:32:05 +00:00
Code Releases Activity

logging: re-level, redact user data at info, and key links by post id

Browse Source 
P0 — level rework + redaction:
- info now carries only lifecycle, per-post business results (sent /
  forwarded / copied / template applied), admin actions and anomalies
  (upload fallback, retry enqueue; dead-letter stays error).
- Per-request detail moved to debug: message/command logging, URL
  extraction, fetching/fetched, link-cache hits, media-group batch sends,
  queue processing (enqueue/processing/completed/rescheduled), photo
  processing (downscale/transcode), inline queries, sensitive-tweet note.
- Full user-submitted URLs and message text now appear only at debug; at
  info and above links are printed via the normalized cache key.

P1 — request correlation:
- handlers::log_key() maps a URL to its normalized post key
  (twitter:<id> / pixiv:<id> / bsky:<handle>/<rkey>). The whole lifecycle
  of one link (fetch -> send -> cache -> fallback) now logs [key=...], so
  multi-worker logs can be correlated by grepping the key.

Convention documented in AGENTS.md.
This commit is contained in:
YoursFunny
2026-08-13 23:34:06 +08:00
parent 47935dd7c6
commit 6b3e61881d
7 changed files with 58 additions and 30 deletions
Download Patch File Download Diff File Expand all files Collapse all files
crates/x-media/src/site/mod.rs
+4 -2
View File
@@ -329,8 +329,10 @@ pub async fn fetch(url: &str) -> Result<Option<Fetched>, FetchError> {
for attempt in 0..3u32 {
match fetch_once(url).await {
Ok(Some(fetched)) => {
log::info!(
"fetched {url}: site {} returned {} media",
// Per-request detail: debug only, keyed by the post id.
log::debug!(
"fetched [key={}]: site {} returned {} media",
cache_key(url).unwrap_or_else(|| "?".into()),
fetched.site_name(),
fetched.media.len()
);
crates/x-media/src/site/twitter/interface.rs
+1 -1
View File
@@ -35,7 +35,7 @@ pub async fn fetch_from_url(url: &str) -> Result<Fetched, FetchError> {
}
}
} else {
log::info!("tweet {id} is sensitive; set TWITTER_AUTH_TOKEN to fetch NSFW media");
log::debug!("tweet {id} is sensitive; set TWITTER_AUTH_TOKEN to fetch NSFW media");
Ok(empty_fetched(url))
}
}
crates/xmedia-bot/src/handlers.rs
+33 -11
View File
@@ -131,6 +131,14 @@ where
.await
}
/// Log prefix tying the whole lifecycle of one link (fetch → send → cache →
/// forward) together: the normalized cache key (`twitter:123…`, `pixiv:123`,
/// `bsky:handle/rkey`) instead of the raw URL, so logs stay short and do not
/// echo full user-submitted URLs at info level.
pub fn log_key(url: &str) -> String {
x_media::site::cache_key(url).unwrap_or_else(|| "<unsupported>".to_string())
}
/// Extracts URL and text-link entities (text + caption), deduped in order.
pub fn extract_urls(message: &Message) -> Vec<String> {
let mut urls = Vec::new();
@@ -534,7 +542,11 @@ async fn dispatch_send(bot: Bot, message: &Message, task: &Task, url: &str) {
};
match result {
Ok(message_ids) => {
log::info!("sent {} message(s) for {url}", message_ids.len());
log::info!(
"sent {} message(s) for [key={}]",
message_ids.len(),
log_key(url)
);
send::post_send_actions(&bot, task, message_ids).await;
// The task settled: drop any keep-alive temp media.
send::release_keep_alive(task);
@@ -543,7 +555,10 @@ async fn dispatch_send(bot: Bot, message: &Message, task: &Task, url: &str) {
delay_seconds,
task,
}) => {
log::info!("send for {url} failed, queued for retry in {delay_seconds:.1}s");
log::info!(
"send for [key={}] failed, queued for retry in {delay_seconds:.1}s",
log_key(url)
);
enqueue_retry(task, delay_seconds).await;
let _ = reply(bot, message.clone(), "Send failed. Task queued for retry.").await;
}
@@ -619,7 +634,7 @@ async fn url_media(bot: Bot, message: &Message, url: &str) {
if let Some(key) = x_media::site::cache_key(url)
&& let Some(cached) = LINK_CACHE.get(&key, CONFIG.link_cache_ttl).await
{
log::info!("link cache hit for {url}");
log::debug!("link cache hit for {key}");
let chat_data = CHAT_STORE.get(chat_id).await;
let site = key.split(':').next().unwrap_or("unknown");
let format = chat_data
@@ -676,11 +691,11 @@ async fn url_media(bot: Bot, message: &Message, url: &str) {
return;
}
log::info!("fetching {url}");
log::debug!("fetching {url} [key={}]", log_key(url));
match x_media::site::fetch(url).await {
// Unsupported links are ignored silently (Python parity).
Ok(None) => {
log::info!("no site pattern matches {url}; ignoring");
log::debug!("no site pattern matches {url}; ignoring");
}
// Retries exhausted: notify the user (Rust-only requirement 3).
Err(e) => {
@@ -763,7 +778,8 @@ pub async fn message_handler(bot: Bot, message: Message) -> Result<(), RequestEr
&t[..end]
})
.unwrap_or("<no text>");
log::info!(
// Per-request detail: debug only (message text is user data).
log::debug!(
"message from {sender} in {} (private={is_private}): {text_preview}",
message.chat.id
);
@@ -774,14 +790,16 @@ pub async fn message_handler(bot: Bot, message: Message) -> Result<(), RequestEr
if let Some(text) = message.text()
&& let Ok(command) = Command::parse(text, "")
{
log::info!("command from {}: {text_preview}", message.chat.id);
log::debug!("command from {}: {text_preview}", message.chat.id);
execute_command(&bot, &message, command).await?;
return respond(());
}
if is_private {
let urls = extract_urls(&message);
if !urls.is_empty() {
log::info!("extracted {} URL(s): {urls:?}", urls.len());
// Debug only, and echo the normalized keys instead of the raw URLs.
let keys: Vec<String> = urls.iter().map(|u| log_key(u)).collect();
log::debug!("extracted {} URL(s): {keys:?}", urls.len());
}
for url in urls {
// Clone out of the lock: the parking_lot guard is !Send and must
@@ -875,7 +893,11 @@ pub async fn inline_query_handler(bot: Bot, query: InlineQuery) -> Result<(), Re
/// Fetches the post behind an inline query and answers it. The caller has
/// already applied the debounce. Returns `true` when an answer was sent.
async fn answer_inline_query(bot: Bot, query: InlineQuery) -> Result<bool, RequestError> {
log::info!("inline query: {}", query.query);
log::debug!(
"inline query: {} [key={}]",
query.query,
log_key(&query.query)
);
match x_media::site::fetch(&query.query).await {
Ok(Some(fetched)) => {
let mut results: Vec<InlineQueryResult> = Vec::new();
@@ -952,7 +974,7 @@ pub async fn callback_query_handler(bot: Bot, query: CallbackQuery) -> Result<()
let chat_data = CHAT_STORE.get(chat_id).await;
let edit = chat_data.edit_message.get(&prompt_message_id).cloned();
let Some(edit) = edit else {
log::info!(
log::debug!(
"callback from {}: no edit record for prompt {prompt_message_id}",
chat_id
);
@@ -1028,7 +1050,7 @@ pub async fn callback_query_handler(bot: Bot, query: CallbackQuery) -> Result<()
}
}
None => {
log::info!("forward callback without a forward channel set");
log::debug!("forward callback without a forward channel set");
bot.answer_callback_query(callback_query_id)
.text("No forward channel set.")
.await?;
crates/xmedia-bot/src/photo.rs
+4 -4
View File
@@ -223,7 +223,7 @@ fn prepare_png(file: NamedTempFile, bytes: &[u8]) -> Result<PhotoPrep, String> {
if w + h <= PHOTO_MAX_DIMENSION_SUM && !size_over {
return Ok(PhotoPrep::Upload(file));
}
log::info!(
log::debug!(
"photo {w}x{h} ({_bit_depth:?} {color_type:?}, {} bytes) needs processing",
bytes.len()
);
@@ -269,7 +269,7 @@ fn prepare_png(file: NamedTempFile, bytes: &[u8]) -> Result<PhotoPrep, String> {
let (nw, nh) = target_dims(w, h);
pix = resize_pix(pix, w, h, nw, nh)?;
(w, h) = (nw, nh);
log::info!("downscaled photo to {w}x{h} (Lanczos3)");
log::debug!("downscaled photo to {w}x{h} (Lanczos3)");
}
let mut png_bytes = Vec::new();
@@ -277,7 +277,7 @@ fn prepare_png(file: NamedTempFile, bytes: &[u8]) -> Result<PhotoPrep, String> {
if png_bytes.len() as u64 <= MAX_UPLOAD_BYTES {
return Ok(PhotoPrep::Upload(write_temp(&png_bytes, "png")?));
}
log::info!("PNG still over the upload cap after processing; transcoding to JPEG");
log::debug!("PNG still over the upload cap after processing; transcoding to JPEG");
let jpeg_bytes = encode_jpeg(&pix, w, h)?;
if jpeg_bytes.len() as u64 <= MAX_UPLOAD_BYTES {
return Ok(PhotoPrep::Upload(write_temp(&jpeg_bytes, "jpg")?));
@@ -311,7 +311,7 @@ fn prepare_jpeg(file: NamedTempFile, bytes: &[u8]) -> Result<PhotoPrep, String>
let (nw, nh) = target_dims(w, h);
pix = resize_pix(pix, w, h, nw, nh)?;
(w, h) = (nw, nh);
log::info!("downscaled jpeg to {w}x{h} (Lanczos3)");
log::debug!("downscaled jpeg to {w}x{h} (Lanczos3)");
}
let jpeg_bytes = encode_jpeg(&pix, w, h)?;
if jpeg_bytes.len() as u64 <= MAX_UPLOAD_BYTES {
crates/xmedia-bot/src/queue.rs
+4 -4
View File
@@ -188,7 +188,7 @@ impl PersistentTaskQueue {
self.counter.fetch_add(1, Ordering::Relaxed)
);
let payload = payload.to_string();
log::info!("enqueued {id} (run_after {run_after:.1})");
log::debug!("enqueued {id} (run_after {run_after:.1})");
self.pool.with_conn(move |conn| {
conn.execute(
"INSERT OR REPLACE INTO tasks (id, payload, run_after, attempts, status, locked_until, created_at) \
@@ -339,10 +339,10 @@ impl QueueWorker {
return;
}
};
log::info!("processing {} (attempt {})", row.id, row.attempts + 1);
log::debug!("processing {} (attempt {})", row.id, row.attempts + 1);
match (self.handler)(payload).await {
Ok(()) => {
log::info!("task {} completed", row.id);
log::debug!("task {} completed", row.id);
self.delete_row(&row.id).await;
}
Err(QueueError::Retryable {
@@ -356,7 +356,7 @@ impl QueueWorker {
(self.dead_letter)(payload, message).await;
} else {
let delay = scaled_retry_delay(delay_seconds, row.attempts);
log::info!(
log::debug!(
"task {} rescheduled in {delay:.1}s (attempt {})",
row.id,
row.attempts + 1
crates/xmedia-bot/src/send.rs
+11 -7
View File
@@ -3,7 +3,7 @@
//! URL is blocked by hotlink protection; the bot downloads the file itself
//! and uploads it via multipart).
use crate::handlers::{CHAT_STORE, LINK_CACHE, TASK_QUEUE};
use crate::handlers::{CHAT_STORE, LINK_CACHE, TASK_QUEUE, log_key};
use crate::link_cache::{CachedMedia, CachedMediaKind, CachedPost};
use crate::photo::{self, MAX_UPLOAD_BYTES, PhotoPrep};
use crate::queue::QueueError;
@@ -232,7 +232,7 @@ async fn cache_sent_task(task: &Task, media: Vec<CachedMedia>) {
post.media = media;
if let Some(key) = x_media::site::cache_key(&post.url) {
LINK_CACHE.put(&key, &post).await;
log::info!("cached send for {}", post.url);
log::debug!("cached send for [key={}]", log_key(&post.url));
}
}
@@ -257,7 +257,7 @@ pub async fn invalidate_cache(task: &Task) {
&& let Some(url) = task.source_url()
&& let Some(key) = x_media::site::cache_key(url)
{
log::info!("removing stale link cache entry for {url}");
log::debug!("removing stale link cache entry for [key={}]", log_key(url));
LINK_CACHE.remove(&key).await;
}
}
@@ -941,7 +941,7 @@ pub async fn send_media_sequence(bot: &Bot, task: &Task) -> Result<Vec<i64>, Sen
.await
{
Ok(messages) => {
log::info!(
log::debug!(
"media group batch {idx}/{} sent ({} item(s))",
media_batches.len(),
batch.len()
@@ -952,7 +952,11 @@ pub async fn send_media_sequence(bot: &Bot, task: &Task) -> Result<Vec<i64>, Sen
Err(RequestError::Api(api)) if is_media_fetch_failure(&api) || is_size_error(&api) => {
log::info!(
"Telegram could not fetch media for batch {idx} ({}), downloading and reuploading",
batch.first().map(item_url).unwrap_or("?")
batch
.first()
.map(item_url)
.map(log_key)
.unwrap_or_else(|| "?".into())
);
match send_batch_via_upload(bot, chat_id, reply_to, batch, caption).await {
Ok(messages) => {
@@ -1048,8 +1052,8 @@ pub async fn send_animation(bot: &Bot, task: &Task) -> Result<Vec<i64>, SendErro
}
Err(RequestError::Api(api)) if is_media_fetch_failure(&api) || is_size_error(&api) => {
log::info!(
"Telegram could not fetch animation URL, downloading and reuploading: {}",
media_url
"Telegram could not fetch animation URL, downloading and reuploading: [key={}]",
log_key(media_url)
);
match download_to_temp(animation).await {
Ok((file, _bytes)) => {