Skip to content

Commit 35ee072

Browse files
lym953claude
andcommitted
fix(metrics): don't hold back invocation metric if initStart already ran
If the Invoke event reaches the processor after platform.initStart (the reverse of the usual On-Demand race), on_invoke_event would still see an empty context_buffer and hold the metric back a second time, with nothing left to flush it until shutdown. Track whether platform.initStart already ran and skip the hold-back in that case. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
1 parent e7646ca commit 35ee072

1 file changed

Lines changed: 78 additions & 3 deletions

File tree

bottlecap/src/lifecycle/invocation/processor.rs

Lines changed: 78 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -63,6 +63,7 @@ pub const DATADOG_INVOCATION_ERROR_KEY: &str = "x-datadog-invocation-error";
6363
const DATADOG_SPAN_ID_KEY: &str = "x-datadog-span-id";
6464
const TAG_SAMPLING_PRIORITY: &str = "_sampling_priority_v1";
6565

66+
#[allow(clippy::struct_excessive_bools)]
6667
pub struct Processor {
6768
/// Buffer containing context of the previous 5 invocations
6869
context_buffer: ContextBuffer,
@@ -114,6 +115,14 @@ pub struct Processor {
114115
/// Timestamp of the cold-start invocation metric in On-Demand mode, held back until
115116
/// `platform.initStart` sets the durable tag so it's not missed on invocation #1.
116117
pending_first_invocation_metric_timestamp: Option<i64>,
118+
/// Whether `platform.initStart` has already been processed for this sandbox.
119+
///
120+
/// Covers the case where the Invoke event reaches the processor after `platform.initStart`
121+
/// (the reverse of the usual On-Demand race). Without this check, `on_invoke_event` would see
122+
/// an empty `context_buffer` (init start doesn't insert a context in On-Demand mode) and hold
123+
/// the metric back again, even though the durable tag is already resolved — and nothing would
124+
/// flush it until `on_shutdown_event`, since `platform.initStart` won't fire again.
125+
platform_init_start_processed: bool,
117126
}
118127

119128
impl Processor {
@@ -158,15 +167,17 @@ impl Processor {
158167
restore_time: None,
159168
init_duration_metric_emitted: false,
160169
pending_first_invocation_metric_timestamp: None,
170+
platform_init_start_processed: false,
161171
}
162172
}
163173

164174
/// Given a `request_id`, creates the context and adds the enhanced metric offsets to the context buffer.
165175
///
166176
pub fn on_invoke_event(&mut self, request_id: String) {
167-
// See `pending_first_invocation_metric_timestamp`.
168-
let is_on_demand_cold_start =
169-
!self.aws_config.is_managed_instance_mode() && self.context_buffer.is_empty();
177+
// See `pending_first_invocation_metric_timestamp` and `platform_init_start_processed`.
178+
let is_on_demand_cold_start = !self.aws_config.is_managed_instance_mode()
179+
&& self.context_buffer.is_empty()
180+
&& !self.platform_init_start_processed;
170181

171182
// In Managed Instance mode, if awaiting the first invocation after init, find and update the empty context created on init start
172183
if self.aws_config.is_managed_instance_mode() && self.awaiting_first_invocation {
@@ -352,6 +363,8 @@ impl Processor {
352363
/// This is used to create a cold start span, since this telemetry event does not
353364
/// provide a `request_id`, we try to guess which invocation is the cold start.
354365
pub fn on_platform_init_start(&mut self, time: DateTime<Utc>, runtime_version: Option<String>) {
366+
self.platform_init_start_processed = true;
367+
355368
if runtime_version
356369
.as_deref()
357370
.is_some_and(|rv| rv.contains("DurableFunction"))
@@ -2179,6 +2192,68 @@ mod tests {
21792192
);
21802193
}
21812194

2195+
#[tokio::test]
2196+
async fn test_on_invoke_event_does_not_hold_metric_if_init_start_already_processed() {
2197+
let mut processor = setup();
2198+
2199+
// `platform.initStart` reaches the processor first (reverse of the usual On-Demand
2200+
// race). It resolves the durable tag but finds no context to attach a cold start span
2201+
// to yet, since On-Demand mode only looks up an existing context here.
2202+
processor.on_platform_init_start(
2203+
Utc::now(),
2204+
Some("python:3.14.DurableFunction.v6".to_string()),
2205+
);
2206+
assert!(processor.platform_init_start_processed);
2207+
assert!(
2208+
processor
2209+
.pending_first_invocation_metric_timestamp
2210+
.is_none(),
2211+
"Nothing should be pending yet, since no invocation has happened"
2212+
);
2213+
2214+
let now: i64 = std::time::UNIX_EPOCH
2215+
.elapsed()
2216+
.expect("unable to poll clock, unrecoverable")
2217+
.as_secs()
2218+
.try_into()
2219+
.unwrap_or_default();
2220+
2221+
// The Invoke event arrives afterwards. Without `platform_init_start_processed`, this
2222+
// would see an empty context_buffer and hold the metric back again — with nothing left
2223+
// to flush it until shutdown, since `platform.initStart` won't fire a second time.
2224+
processor.on_invoke_event("req-1".to_string());
2225+
assert!(
2226+
processor
2227+
.pending_first_invocation_metric_timestamp
2228+
.is_none(),
2229+
"Expected the invocation metric to be emitted immediately, not held back"
2230+
);
2231+
2232+
let runtime = processor
2233+
.runtime
2234+
.clone()
2235+
.expect("runtime should have been resolved by on_invoke_event");
2236+
let ts = (now / 10) * 10;
2237+
let expected_tags = dogstatsd::metric::SortedTags::parse(&format!(
2238+
"cold_start:true,durable_function:true,runtime:{runtime}"
2239+
))
2240+
.ok();
2241+
let entry = processor
2242+
.enhanced_metrics
2243+
.aggr_handle
2244+
.get_entry_by_id(
2245+
crate::metrics::enhanced::constants::INVOCATIONS_METRIC.into(),
2246+
expected_tags,
2247+
ts,
2248+
)
2249+
.await
2250+
.unwrap();
2251+
assert!(
2252+
entry.is_some(),
2253+
"Expected the immediately-emitted invocation metric to carry the durable_function:true tag"
2254+
);
2255+
}
2256+
21822257
#[tokio::test]
21832258
async fn test_init_duration_emitted_from_init_report() {
21842259
let mut processor = setup();

0 commit comments

Comments
 (0)