feat: implement the Telemetry API - #183
Conversation
Extensions can subscribe to the Telemetry API, but the emulator answers with Telemetry.NotSupported and never delivers anything, so extensions that consume telemetry cannot be exercised locally at all. This is issue aws#94. The pieces were nearly all present. NewServer already mounts the real TelemetryAPIRouter when EnableTelemetryAPI is set; StandaloneEventsAPI already builds records for the documented event types; StandaloneLogsEgressAPI already distinguishes a function's output from an extension's. What was missing was an implementation of telemetry.SubscriptionAPI -- only NoOpSubscriptionAPI exists -- and something to deliver events to subscribers. TelemetrySubscriptionService fills that gap. It validates subscriptions, honors the types filter and all three buffering limits, rewrites the sandbox hostname that only resolves inside a real execution environment, and posts batches to each subscriber. Events reach it through a dispatcher hook on the events API, so subscribers receive platform records as objects and log lines as strings, which is the distinction the API defines. Three behaviors worth calling out, each learned by comparing against telemetry captured from a real function: - The sandbox calls TurnOff() once initialization ends. That closes the subscription window; it must not stop delivery to extensions already subscribed, or everything after init is lost. - Initialization telemetry is emitted before an extension has had the chance to subscribe. Real Lambda delivers it regardless, so events produced before the first subscription are held, bounded, and replayed to each new subscriber. Without this, platform.initStart never arrives, which is exactly what an extension reporting cold starts needs. - Nothing called EventsAPI.SendReport, so platform.report was never produced even though the emulator prints a REPORT line. It is now reported where that line is printed. platform.end is deliberately not emitted: it does not appear in telemetry captured from a real function under the current schema version. Console output is unchanged. The logs egress tees to stdout as well as reporting telemetry, so docker logs still shows the runtime's and extensions' output. Verified by running an extension that records every delivered request body, inside the emulator, and diffing the result against telemetry captured from a real Lambda function invoked with the same handler: the set of event types now matches exactly. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
| log.WithError(err).Warn("Telemetry API: could not encode a batch") | ||
| return | ||
| } | ||
| response, err := http.Post(sub.destination, "application/json", bytes.NewReader(body)) |
There was a problem hiding this comment.
[RESOURCE_MANAGEMENT] Delivery uses http.Post, which calls http.DefaultClient with a zero timeout — it will block indefinitely if a subscriber accepts the connection and never responds (or is slow). Because deliver is invoked synchronously from enqueue when maxItems/maxBytes is reached, and enqueue is called on the caller's goroutine of Dispatch (which runs on the event‑production path via StandaloneEventsAPI.appendEvent), a hung subscriber can stall the emulator's event pipeline. A misbehaving extension running under RIE can wedge the whole runtime.
Use a client with an explicit timeout:
var telemetryHTTPClient = &http.Client{Timeout: 10 time.Second}
// ...
response, err := telemetryHTTPClient.Post(sub.destination, "application/json", bytes.NewReader(body))There was a problem hiding this comment.
Fixed in 7f0923d. Delivery now uses a dedicated client with a timeout rather than http.DefaultClient.
I went with 5s rather than 10s: since a size-triggered batch is delivered on the goroutine producing the event, the timeout is how long the sandbox's event pipeline can be stalled, and for a local emulator giving up sooner seemed better than waiting longer. Happy to change it if you'd rather match something.
TestDeliveryToAHungSubscriberDoesNotBlockForever covers it with a subscriber that accepts the connection and never answers.
🤖 Generated with Claude Code
| telemetryEvents.Dispatch(standalonetelemetry.SandboxEvent{ | ||
| Time: now, | ||
| Type: "platform.report", | ||
| PlatformEvent: map[string]interface{}{ |
There was a problem hiding this comment.
[BUG] printEndReports emits platform.report with "status": "success" unconditionally, but the same function is called from the timeout path in InvokeHandler (case rapidcore.ErrInvokeTimeout: printEndReports(...)). A timed‑out invoke will be reported to subscribers as a successful one, which is exactly the signal extensions like ADOT/Datadog use to alarm on. Real Lambda emits "status": "timeout" (and "error" for failures).
Thread the status through the call, e.g.:
func printEndReports(invokeId, initDuration, memorySize string, invokeStart time.Time, timeoutDuration time.Duration, status string) {
// ...
"status": status,and pass "timeout" from the ErrInvokeTimeout branch and "success" from the normal completion path.
There was a problem hiding this comment.
yes, on timeout, the status should be "timeout"
There was a problem hiding this comment.
Fixed in 7f0923d, and thanks @luben for confirming. The status is threaded through printEndReports, with "timeout" from the ErrInvokeTimeout branch and "success" from the normal path. TestReportRecordCarriesTheInvocationStatus covers both.
🤖 Generated with Claude Code
| "requestId": invokeId, | ||
| "status": "success", | ||
| "metrics": map[string]interface{}{ | ||
| "durationMs": invokeDuration, |
There was a problem hiding this comment.
[BUG] memorySize is a string (from GetenvWithDefault("AWSLAMBDA_FUNCTION_MEMORY_SIZE", "3008")), so both memorySizeMB and maxMemoryUsedMB are serialized as JSON strings ("3008") rather than numbers. The Telemetry API schema defines these as numeric integers; consumers that decode them with typed structs or numeric JSON paths (ADOT, Datadog, X‑Ray forwarders, etc.) will fail or silently drop these metrics. Parse to an int before emitting:
memorySizeMB, := strconv.Atoi(memorySize)
// ...
"metrics": map[string]interface{}{
"durationMs": invokeDuration,
"billedDurationMs": math.Ceil(invokeDuration),
"memorySizeMB": memorySizeMB,
"maxMemoryUsedMB": memorySizeMB,
},There was a problem hiding this comment.
Fixed in 7f0923d. The memory size is parsed to an int, so the metrics serialize as numbers; TestReportRecordMetricsAreNumbers decodes the record into a typed struct, which is what would have failed before.
While confirming against telemetry captured from a real function I also noticed the report should carry initDurationMs on a cold start, so that's added, present only when the invocation initialized the environment.
Worth admitting this one found a hole in my own verification: I had compared which event types the emulator produced against the real capture, but not the field types within each record — which is exactly where this lived. I've since compared field by field, and the remaining differences are in the PR description.
🤖 Generated with Claude Code
| record.Record = event.LogMessage | ||
| } | ||
|
|
||
| if len(subscriptions) == 0 { |
There was a problem hiding this comment.
[CONCURRENCY] Dispatch snapshots the subscription map under the lock, then re-acquires the lock later to append to earlyEvents only if the snapshot was empty. A Subscribe call interleaving between those two lock sections drops the event:
Dispatch(e)takes the lock, seessubscriptionsis empty, releases.Subscribetakes the lock, inserts a new subscription, copiesearlyEvents(which does not yet containe), releases, replays copied events (nothing).Dispatchtakes the lock again and appendsetoearlyEvents— no live subscription will ever be handede, and furtherSubscribecalls may not occur.
Because subscribes happen during extension init and the sandbox produces platform events during that same window, this is exactly the ordering the code is meant to handle. Decide the empty-vs-non-empty branch under a single held lock:
s.lock.Lock()
if len(s.subscriptions) == 0 {
if len(s.earlyEvents) < maxEarlyEvents {
s.earlyEvents = append(s.earlyEvents, record)
}
s.lock.Unlock()
return
}
subscriptions := make([]subscription, 0, len(s.subscriptions))
for , sub := range s.subscriptions {
subscriptions = append(subscriptions, sub)
}
s.lock.Unlock()There was a problem hiding this comment.
Fixed in 7f0923d. The buffer-versus-deliver decision now happens under a single held lock, so a Subscribe can't interleave between the two sections and strand the event.
One caveat I'd rather state than gloss: I could not get a test to reproduce this. The two lock sections were adjacent with almost no work between them, and 400 attempts of concurrent Subscribe/Dispatch never hit the window. There is a concurrency test for the race detector, but it passes against the buggy version too, so it is not a regression test — this fix rests on reading the code, and on your analysis above.
🤖 Generated with Claude Code
Four problems, all reachable in normal use: Delivery used http.DefaultClient, which has no timeout. Batches that reach a size limit are delivered on the goroutine producing the event, so a subscriber that accepted a connection and never answered would stall the sandbox's event pipeline. Delivery now uses a client that gives up. platform.report was emitted with status success unconditionally, including from the invoke-timeout path, so a timed-out invocation was reported as a successful one -- the opposite of what an extension watching that field needs. The status is now threaded through. The report's memory metrics were serialized as JSON strings, because the memory size arrives as one. The Telemetry API defines them as numbers, and a consumer decoding into a typed struct rejects strings. They are parsed now, and the report also carries initDurationMs on a cold start, as a real function's does. Dispatch decided whether to buffer or deliver in one lock section and acted in another. A Subscribe interleaving between the two would insert itself, replay a copy of the buffer that did not yet hold the event, and leave the event buffered for nobody -- precisely the ordering the buffer exists to handle. The decision now happens under a single held lock. Tests cover the timeout, the status, the numeric metrics and the cold-start figure. The lost-event window is not covered: the two lock sections it needed to interleave between were adjacent and 400 attempts never hit it, so that fix rests on reading the code rather than on a failing test. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
@vicheey , can you review it. From telemetry perspective it looks good to me, but I cannot asses if it fits well in the architecture. |
Implements the Telemetry API. Fixes #94.
Today an extension can call
PUT /2022-07-01/telemetryand gets202with{"errorType":"Telemetry.NotSupported"}, and nothing is ever delivered. Any extension whose purpose is consuming telemetry — ADOT, Datadog, Honeycomb's — can't be exercised locally at all.Approach
Nearly all of the machinery was already here:
NewServeralready mounts the realTelemetryAPIRouterwhenEnableTelemetryAPIis set, falling back to the stub otherwise.sandbox_builder.gohardcodes it tofalseand nothing callsSetTelemetrySubscription, which is what would flip it.StandaloneEventsAPIalready builds records for the documented event types —platform.initStart,platform.start,platform.runtimeDone,platform.extension, and so on.StandaloneLogsEgressAPIalready separates a function's output from an extension's own.What was missing was an implementation of
telemetry.SubscriptionAPI(onlyNoOpSubscriptionAPIexists publicly) and something to deliver events to subscribers. This adds both and wires them through the existing setters.TelemetrySubscriptionServicevalidates subscriptions, honors thetypesfilter and all three buffering limits (timeoutMs,maxItems,maxBytes), rewrites thesandboxhostname that only resolves inside a real execution environment, and POSTs batches to each subscriber. Events reach it via a dispatcher hook on the events API, so platform records arrive as objects and log lines as strings — the distinction the API defines and that consumers branch on.Console output is unchanged: the logs egress tees to stdout as well as reporting telemetry, so
docker logsstill shows everything it did before.Three things that only showed up against real telemetry
I captured telemetry from an actual deployed Lambda function and diffed it against what the emulator produced. Each of these was a bug found that way:
TurnOff()closes the subscription window, it does not stop delivery. The sandbox calls it once initialization finishes (handlers.go:397, "no more agents can be subscribed"). My first version treated it as a delivery kill switch, so everything after init silently vanished.platform.initStartnever arrives — precisely what an extension measuring cold starts needs.EventsAPI.SendReport, soplatform.reportwas never produced despite the emulator printing aREPORTline. It's now reported where that line is printed.platform.endis deliberately not emitted: it doesn't appear in telemetry captured from a real function under the current schema version.Verification
An extension that records every delivered request body, run inside the emulator, diffed against telemetry captured from a real Lambda function invoked with the same handler. The set of delivered event types now matches exactly:
Covering
function,platform.initStart,platform.initRuntimeDone,platform.initReport,platform.start,platform.runtimeDone,platform.report,platform.extension, andplatform.telemetrySubscription.Comparing the records field by field rather than only their types — which is how the string-versus-number metrics slipped past my first pass — these differences remain:
platform.reportspansarray (extensionOverhead,responseLatency); the emulator has no such measurementsplatform.initReportstatus;interop.InitReportDatacarries no status, so the emulator does not have itplatform.startfunctionArnplatform.initStartfunctionArnandruntimeArnplatform.runtimeDoneinternalMetricsandtenantIdThe last three come from the existing record builders in
StandaloneEventsAPIrather than from this change, so I have left them alone rather than widen the diff — happy to follow up if you would rather they matched.Then end to end with Honeycomb's Lambda extension, which translates OTLP found in function stdout: it received the telemetry, translated the spans, and delivered them to a stand-in API with the correct per-service routing — the whole path exercised locally with no AWS involved.
Unit tests cover record shapes, type filtering, pre-subscription replay, the
TurnOffsemantics above,Clearon reset,maxItemsflushing, rejection of unusable subscription requests, and hostname rewriting.go test ./internal/lambda/...passes unchanged.Why not build on #137
@AndrewChubatiuk got there first in #137 and deserves the credit for pushing on this; I tried that branch before writing anything. I didn't extend it because the mechanism seemed hard to make faithful, and I'd rather explain that than quietly duplicate the work:
EnableTelemetryAPIstaysfalseand the response remains202 Telemetry.NotSupportedeven when telemetry will be delivered. An extension that checks the subscribe status treats that as failure — mine exited, and the emulator reportedExtension.Crash→Init failed.os.Stdout/os.Stderrprocess-wide and re-emitting every line, so all telemetry is typedfunction.START RequestId: ...arrives as a function log line where real Lambda sends a structuredplatform.start, and noplatform.*events are delivered at all.functiontelemetry. For an extension that logs while handling telemetry that's a feedback loop; I had to write my test captures to a file rather than stdout to measure anything.Concretely, same handler, same invoke: #137 delivers 10 messages all typed
function; real Lambda delivers 20 across nine types.None of that is a knock on the contribution — it unblocked the case it was tested against. It's that going through the existing
EventsAPI/LogsEgressAPIabstractions gets the types, the record shapes, and the subscribe response right by construction, rather than needing to reconstruct them from a line of text.@valerena, you mentioned discussing this with the internal Lambda team. If there's an internal implementation this should converge with, I'm happy to adapt or drop this in favour of it — the captured-from-real-Lambda comparison above is probably reusable either way as a conformance check.
Disclosure: I work at Honeycomb and maintain the extension linked above, so local Telemetry API support is directly useful to me. The captured-from-real-Lambda comparison is vendor-neutral, though, and I'd expect it to be just as useful for ADOT or any other telemetry-consuming extension.
🤖 Generated with Claude Code