Skip to content

Commit b260205

Browse files
authored
chore: Add a timer to avoid repeated debug logs (#954)
## Problem When the Lambda runtime spins down, the extension may enter a loop waiting for unfinished work, printing up to 100,000s identical lines of log: > LOGS_AGENT | No more events to process but still have senders, continuing to drain... For example, in one of my tests, this line was printed 31602 times within 1.28 seconds. <img width="1097" height="344" alt="image" src="https://github.com/user-attachments/assets/b3aff30c-596f-4837-a081-fbe165ba6254" /> This: 1. slightly complicates debugging for our engineers 2. adds costs and confusion for customers who turn on `DD_LOG_LEVEL=debug` to debug the extension ## This PR Add a timer and print this line at most once every 100ms, so it will be printed at most 20 times within the 2-second spindown time. ## Testing No testing for now. Should be straightforward. Will see if logs are reduced in future debugging.
1 parent 0d69a7b commit b260205

1 file changed

Lines changed: 10 additions & 1 deletion

File tree

bottlecap/src/logs/agent.rs

Lines changed: 10 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
use std::sync::Arc;
2+
use std::time::{Duration, Instant};
23
use tokio::sync::mpsc::{self, Sender};
34
use tokio_util::sync::CancellationToken;
45
use tracing::debug;
@@ -9,6 +10,8 @@ use crate::logs::{aggregator_service::AggregatorHandle, processor::LogsProcessor
910
use crate::tags;
1011
use crate::{LAMBDA_RUNTIME_SLUG, config};
1112

13+
const DRAIN_LOG_INTERVAL: Duration = Duration::from_millis(100);
14+
1215
#[allow(clippy::module_name_repetitions)]
1316
pub struct LogsAgent {
1417
rx: mpsc::Receiver<TelemetryEvent>,
@@ -57,6 +60,7 @@ impl LogsAgent {
5760
debug!("LOGS_AGENT | Received shutdown signal, draining remaining events");
5861

5962
// Drain remaining events
63+
let mut last_drain_log_time = Instant::now().checked_sub(DRAIN_LOG_INTERVAL).expect("Failed to subtract interval from now");
6064
'drain_logs_loop: loop {
6165
match self.rx.try_recv() {
6266
Ok(event) => {
@@ -68,7 +72,12 @@ impl LogsAgent {
6872
},
6973
// Empty signals there are still outstanding senders
7074
Err(tokio::sync::mpsc::error::TryRecvError::Empty) => {
71-
debug!("LOGS_AGENT | No more events to process but still have senders, continuing to drain...");
75+
// Log at most once every 100ms to avoid spamming the logs
76+
let now = Instant::now();
77+
if now.duration_since(last_drain_log_time) >= DRAIN_LOG_INTERVAL {
78+
debug!("LOGS_AGENT | No more events to process but still have senders, continuing to drain...");
79+
last_drain_log_time = now;
80+
}
7281
},
7382
}
7483
}

0 commit comments

Comments
 (0)