-
Notifications
You must be signed in to change notification settings - Fork 63
feat(telemetry): setup client with logging sink #1846
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
5031ae9
8fc7950
7c03c41
d4bffc9
69ca5c4
e561a2f
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,131 @@ | ||
| import { test, describe, beforeEach, afterEach, expect } from "bun:test"; | ||
| import { join } from "node:path"; | ||
| import { mkdtemp, rm } from "node:fs/promises"; | ||
| import { tmpdir } from "node:os"; | ||
| import { DefaultTelemetryClient } from "./client"; | ||
| import { TelemetryAttributesRecorder } from "./recorder"; | ||
| import { createFileLogger, type Logger } from "../logging"; | ||
| import { LOG_LEVEL } from "../logging"; | ||
| import { assertLogsMatch, TestGlobalConfigAccessor } from "../testing"; | ||
| import type { MetricSink } from "./types"; | ||
| import { LoggingSink } from "./loggingSink"; | ||
|
|
||
| describe("DefaultTelemetryClient", () => { | ||
| let tempDir: string; | ||
| let logger: Logger; | ||
|
|
||
| beforeEach(async () => { | ||
| tempDir = await mkdtemp(join(tmpdir(), "telemetry-client-test-")); | ||
| logger = createFileLogger({ | ||
| filePath: join(tempDir, "output"), | ||
| logLevel: LOG_LEVEL.DEBUG, | ||
| }); | ||
| }); | ||
|
|
||
| afterEach(async () => { | ||
| await rm(tempDir, { recursive: true, force: true }); | ||
| }); | ||
|
|
||
| test("emits metrics with resource and command attributes to configured sinks", async () => { | ||
| const sink = new LoggingSink({ logger: logger.child({ module: "loggingSink" }) }); | ||
| const sessionId = "aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee"; | ||
| const globalConfigAccessor = new TestGlobalConfigAccessor(); | ||
| const client = new DefaultTelemetryClient({ | ||
| logger, | ||
| sessionId, | ||
| globalConfigAccessor, | ||
| metricSinks: [sink], | ||
| }); | ||
|
|
||
| const recorder = new TelemetryAttributesRecorder("cli.command_run", { exit_reason: "success" }); | ||
|
|
||
| recorder.record({ exit_reason: "failure" }); | ||
|
|
||
| await client.emit("cli.command_run", 123, recorder.getAttributes()); | ||
|
|
||
| expect(sink.getName()).toBe("LoggingSink"); | ||
| await sink.shutdown(); | ||
| await client.shutdown(); | ||
|
|
||
| const { installationId } = await globalConfigAccessor.get(); | ||
| await assertLogsMatch(tempDir, [ | ||
| { | ||
| filter: (log: any) => | ||
| log.metricName === "cli.command_run" && | ||
| log.metricValue === 123 && | ||
| log.metricAttributes?.["exit_reason"] === "failure" && | ||
| log.metricAttributes?.["service.name"] === "agentcore-cli" && | ||
| log.metricAttributes?.["agentcore-cli.session_id"] === sessionId && | ||
| log.metricAttributes?.["agentcore-cli.installation_id"] === installationId, | ||
| expectedCount: 1, | ||
| }, | ||
| ]); | ||
| }); | ||
|
|
||
| test("throws when recorder has incomplete attributes", async () => { | ||
| const client = new DefaultTelemetryClient({ | ||
| logger, | ||
| sessionId: "aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee", | ||
| globalConfigAccessor: new TestGlobalConfigAccessor(), | ||
| metricSinks: [], | ||
| }); | ||
|
|
||
| const recorder = new TelemetryAttributesRecorder("cli.command_run"); | ||
|
|
||
| expect(() => client.emit("cli.command_run", 100, recorder.getAttributes())).toThrow(); | ||
| await client.shutdown(); | ||
| }); | ||
|
|
||
| test("handles sink errors gracefully without throwing", async () => { | ||
| const recordedMetrics: string[] = []; | ||
| const goodSink: MetricSink = { | ||
| getName: () => "GoodSink", | ||
| send: (metricName) => { | ||
| recordedMetrics.push(metricName); | ||
| }, | ||
| shutdown: async () => {}, | ||
| }; | ||
|
|
||
| const badSink: MetricSink = { | ||
| getName: () => "BadSink", | ||
| send: () => { | ||
| throw new Error("record exploded"); | ||
| }, | ||
| shutdown: async () => { | ||
| throw new Error("shutdown exploded"); | ||
| }, | ||
| }; | ||
|
|
||
| const client = new DefaultTelemetryClient({ | ||
| logger, | ||
| sessionId: "aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee", | ||
| globalConfigAccessor: new TestGlobalConfigAccessor(), | ||
| metricSinks: [badSink, goodSink], | ||
| }); | ||
|
|
||
| // emit should not throw even though the sink's record() throws | ||
| await client.emit("cli.command_run", 100, { exit_reason: "success" }); | ||
| // shutdown should not throw even though the sink's shutdown() rejects | ||
| await client.shutdown(); | ||
|
|
||
| // GoodSink still receives data despite BadSink throwing | ||
| expect(recordedMetrics).toEqual(["cli.command_run"]); | ||
|
|
||
| await assertLogsMatch(tempDir, [ | ||
| { | ||
| filter: (log: any) => | ||
| log.msg === "failed to record to sink 'BadSink'" && | ||
| log.errorName === "Error" && | ||
| log.errorMessage === "record exploded", | ||
| expectedCount: 1, | ||
| }, | ||
| { | ||
| filter: (log: any) => | ||
| log.msg === "failed to shutdown metric sink with name 'BadSink'" && | ||
| log.errorName === "Error" && | ||
| log.errorMessage === "shutdown exploded", | ||
| expectedCount: 1, | ||
| }, | ||
| ]); | ||
| }); | ||
| }); |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,115 @@ | ||
| import type { Logger } from "../logging"; | ||
| import { LoggingSink } from "./loggingSink"; | ||
| import { resourceAttributesSchema, type ResourceAttributes } from "./shapes"; | ||
| import os from "os"; | ||
| import { | ||
| type AttributesOf, | ||
| type MetricSink, | ||
| type TelemetryClient, | ||
| type ValueOf, | ||
| METRICS, | ||
| type MetricName, | ||
| } from "./types"; | ||
| import type { GlobalConfigAccessor } from "../globalConfig"; | ||
|
|
||
| export type DefaultTelemetryClientConfig = { | ||
| logger: Logger; | ||
| globalConfigAccessor: GlobalConfigAccessor; | ||
| sessionId: string; | ||
| metricSinks?: MetricSink[]; | ||
| }; | ||
|
|
||
| /** | ||
| * Implements {@link TelemetryClient} by validating and fanning out metrics to a list of {@link MetricSink} implementations. | ||
| */ | ||
| export class DefaultTelemetryClient implements TelemetryClient { | ||
| private logger: Logger; | ||
| private readonly sessionId: string; | ||
| private globalConfigAccessor: GlobalConfigAccessor; | ||
| private resourceAttributes: ResourceAttributes | undefined; | ||
| private metricSinks: MetricSink[] | undefined; | ||
|
|
||
| constructor(config: DefaultTelemetryClientConfig) { | ||
| this.logger = config.logger; | ||
| this.sessionId = config.sessionId; | ||
| this.globalConfigAccessor = config.globalConfigAccessor; | ||
| this.resourceAttributes = undefined; | ||
| this.metricSinks = config.metricSinks; | ||
| } | ||
|
|
||
| async emit<TMetricName extends MetricName>( | ||
| metricName: TMetricName, | ||
| metricValue: ValueOf<TMetricName>, | ||
| metricAttributes: AttributesOf<TMetricName>, | ||
| ): Promise<void> { | ||
| try { | ||
| const metricSinks = this.getMetricSinks(); | ||
| const resourceAttributes = await this.getResourceAttributes(); | ||
| // merge in resource attributes with metric attributes before sending to sink. | ||
| const attributes = { | ||
| ...resourceAttributes, | ||
| ...metricAttributes, | ||
| }; | ||
|
|
||
| const validatedMetricValue = METRICS[metricName]["valueSchema"].parse(metricValue); | ||
|
|
||
| metricSinks.forEach((sink) => { | ||
| try { | ||
| sink.send(metricName, validatedMetricValue, attributes); | ||
| } catch (e) { | ||
| const error = e instanceof Error ? e : new Error(String(e)); | ||
| this.logger | ||
| .child({ errorName: error.name, errorMessage: error.message }) | ||
| .warn(`failed to record to sink '${sink.getName()}'`); | ||
| // do not allow a single sink failure to fail other sinks. | ||
| } | ||
| }); | ||
| } catch (e) { | ||
| const error = e instanceof Error ? e : new Error(String(e)); | ||
| this.logger | ||
| .child({ errorName: error.name, errorMessage: error.message }) | ||
| .warn(`failed to emit telemetry`); | ||
| // telemetry is best-effort, don't throw. | ||
| } | ||
| } | ||
|
|
||
| async shutdown(): Promise<void> { | ||
| const metricSinks = this.getMetricSinks(); | ||
|
|
||
| const promises = metricSinks.map(async (sink) => { | ||
| return sink.shutdown().catch((e) => { | ||
| const error = e instanceof Error ? e : new Error(String(e)); | ||
| this.logger | ||
| .child({ errorName: error.name, errorMessage: error.message }) | ||
| .warn(`failed to shutdown metric sink with name '${sink.getName()}'`); | ||
| }); | ||
| }); | ||
| await Promise.all(promises); | ||
| } | ||
|
|
||
| private getMetricSinks(): MetricSink[] { | ||
| if (this.metricSinks !== undefined) return this.metricSinks; | ||
|
|
||
|
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. this will be async once we add fs sink for audit, so following lazy init pattern from attributes below. |
||
| this.metricSinks = [new LoggingSink({ logger: this.logger.child({ module: "loggingSink" }) })]; | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. It seems the default Logging sink is created and invoked still without resolving the telemetry preference. The persisted-config case also records again from a second CLI process, so this is not limited to the command that changes the setting. CONFIG_HOME="$(mktemp -d /tmp/pr1846-config-test.XXXXXX)"
ENV_HOME="$(mktemp -d /tmp/pr1846-env-test.XXXXXX)"
# Persist the opt-out. This currently records one telemetry entry.
HOME="$CONFIG_HOME" bun run src/index.ts config telemetry.enabled false
CONFIG_LOG="$(find "$CONFIG_HOME/.agentcore/logs" -name 'output-*.log' -print -quit)"
rg -c '"msg":"recording telemetry"' "$CONFIG_LOG"
# 1
# Start another process with the persisted opt-out. It records another entry.
HOME="$CONFIG_HOME" bun run src/index.ts config telemetry.enabled
rg -c '"msg":"recording telemetry"' "$CONFIG_LOG"
# 2
# The environment override is also ignored.
HOME="$ENV_HOME" AGENTCORE_TELEMETRY_DISABLED=1 bun run src/index.ts config telemetry.enabled
ENV_LOG="$(find "$ENV_HOME/.agentcore/logs" -name 'output-*.log' -print -quit)"
rg -c '"msg":"recording telemetry"' "$ENV_LOG"
# 1Shouldn't the resolved default sink list be empty when telemetry is disabled?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I left it on because I think we want users to be able to audit telemetry without enabling it sent to the collector. I.e. maybe i disabled it, but I'm curious what would be sent. I do think we should disable logging when its not being sent or auditted (since its misleading), but I'll address that when I add the next sink. |
||
|
|
||
| return this.metricSinks; | ||
| } | ||
|
|
||
| private async getResourceAttributes(): Promise<ResourceAttributes> { | ||
| if (this.resourceAttributes !== undefined) return this.resourceAttributes; | ||
|
|
||
| const globalConfig = await this.globalConfigAccessor.get(); | ||
| this.resourceAttributes = resourceAttributesSchema.parse({ | ||
| "service.name": "agentcore-cli", | ||
| // TODO: wire up real package version. | ||
| "service.version": "0.0.0", | ||
| "agentcore-cli.installation_id": globalConfig.installationId, | ||
| "agentcore-cli.session_id": this.sessionId, | ||
| "os.type": os.type(), | ||
| "os.version": os.release(), | ||
| "host.arch": os.arch(), | ||
| "node.version": process.version, | ||
|
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. if I run this via bun, I get the wrong value here since bun hard-codes it for compatibility. However, when using the build for node, it does return the correct version. |
||
| }); | ||
| return this.resourceAttributes; | ||
| } | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,3 @@ | ||
| export { DefaultTelemetryClient } from "./client"; | ||
| export { TelemetryAttributesRecorder } from "./recorder"; | ||
| export { type AttributesOf } from "./types"; |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,31 @@ | ||
| import type { Logger } from "../logging"; | ||
| import type { MetricSink } from "./types"; | ||
|
|
||
| type LoggingSinkConfig = { | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. compliment: I love how you decided to make a config object instead of just passing logger. This allows to add more parameters if we need to.
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Agreed I really like that system |
||
| logger: Logger; | ||
| }; | ||
|
|
||
| /** | ||
| * An implementation of {@link MetricSink} that logs metrics using the given logger | ||
| */ | ||
| export class LoggingSink implements MetricSink { | ||
| private logger: Logger; | ||
|
|
||
| constructor(config: LoggingSinkConfig) { | ||
| this.logger = config.logger; | ||
| } | ||
|
|
||
| send( | ||
| metricName: string, | ||
| metricValue: number, | ||
| metricAttributes: Record<string, string | number>, | ||
| ): void { | ||
| this.logger.child({ metricName, metricValue, metricAttributes }).info("recording telemetry"); | ||
| } | ||
|
|
||
| async shutdown(): Promise<void> {} | ||
|
|
||
| getName() { | ||
| return "LoggingSink"; | ||
| } | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,35 @@ | ||
| import { type MetricName, type AttributesOf, METRICS } from "./types"; | ||
|
|
||
| /** | ||
| * A strongly typed recorder for accumulating metric attributes, bound to a specific metric's schema. | ||
| */ | ||
| export class TelemetryAttributesRecorder<TMetricName extends MetricName> { | ||
| private attributes: Partial<AttributesOf<TMetricName>>; | ||
|
|
||
| constructor( | ||
| private readonly metricName: TMetricName, | ||
| initialAttributes: Partial<AttributesOf<TMetricName>> = {}, | ||
| ) { | ||
| this.attributes = initialAttributes; | ||
| } | ||
|
|
||
| /** | ||
| * Retrieves the underlying attributes and validates them against the metric schema. | ||
| * Throws if metric shape is invalid. | ||
| */ | ||
| getAttributes(): AttributesOf<TMetricName> { | ||
| const attributes = METRICS[this.metricName]["attributeSchema"].parse(this.attributes); | ||
| return attributes as AttributesOf<TMetricName>; | ||
| } | ||
|
|
||
| /** | ||
| * Add attributes that overwrite existing values if already set. | ||
| */ | ||
| record(data: Partial<AttributesOf<TMetricName>>): Partial<AttributesOf<TMetricName>> { | ||
| this.attributes = { | ||
| ...this.attributes, | ||
| ...data, | ||
| }; | ||
| return this.attributes; | ||
| } | ||
| } |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
this is what we can pass down the context (will wire up in a future PR).