Skip to content
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

feat(instrumentation-aws-lambda): In AWS Lambda instrumentation, extend invocation span start time back to Lambda environment startup time on coldstart #2533

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -232,6 +232,9 @@ export class AwsLambdaInstrumentation extends InstrumentationBase<AwsLambdaInstr
const span = plugin.tracer.startSpan(
name,
{
// For coldstarts,
// use Lambda start time as invocation span start time to take initialization time into account.
startTime: requestIsColdStart ? lambdaStartTime : Date.now(),
kind: SpanKind.SERVER,
attributes: {
[SEMATTRS_FAAS_EXECUTION]: context.awsRequestId,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,10 @@ import {
defaultTextMapGetter,
} from '@opentelemetry/api';
import { AWSXRayPropagator } from '@opentelemetry/propagator-aws-xray';
import { W3CTraceContextPropagator } from '@opentelemetry/core';
import {
hrTimeToMilliseconds,
W3CTraceContextPropagator,
} from '@opentelemetry/core';
import { AWSXRayLambdaPropagator } from '@opentelemetry/propagator-aws-xray-lambda';

const memoryExporter = new InMemorySpanExporter();
Expand Down Expand Up @@ -266,10 +269,15 @@ describe('lambda handler', () => {
});

it('should record coldstart', async () => {
initializeHandler('lambda-test/sync.handler');
const time0 = Date.now();
initializeHandler('lambda-test/sync.handler', { lambdaStartTime: time0 });

// Simulate initialization time
await new Promise(resolve => setTimeout(resolve, 10));

const handlerModule = lambdaRequire('lambda-test/sync');

const time1 = Date.now();
const result1 = await new Promise((resolve, reject) => {
handlerModule.handler('arg', ctx, (err: Error, res: any) => {
if (err) {
Expand All @@ -280,6 +288,7 @@ describe('lambda handler', () => {
});
});

const time2 = Date.now();
const result2 = await new Promise((resolve, reject) => {
handlerModule.handler('arg', ctx, (err: Error, res: any) => {
if (err) {
Expand All @@ -298,18 +307,28 @@ describe('lambda handler', () => {
assertSpanSuccess(span1);
assert.strictEqual(span1.parentSpanId, undefined);
assert.strictEqual(span1.attributes[SEMATTRS_FAAS_COLDSTART], true);
// Since it is coldstart, invocation span start time should be equal to lambda start time
assert.strictEqual(hrTimeToMilliseconds(span1.startTime), time0);
// Since it is coldstart, invocation span start time should be before actual handler call time
assert.ok(hrTimeToMilliseconds(span1.startTime) < time1);

assert.strictEqual(result2, 'ok');
assertSpanSuccess(span2);
assert.strictEqual(span2.parentSpanId, undefined);
assert.strictEqual(span2.attributes[SEMATTRS_FAAS_COLDSTART], false);
// Since it is warm invocation, invocation span start time should be after than lambda start time
assert.ok(hrTimeToMilliseconds(span2.startTime) > time0);
// Since it is warm invocation, invocation span start time should be equal or after than handler call time
assert.ok(hrTimeToMilliseconds(span2.startTime) >= time2);
});

it('should record coldstart with provisioned concurrency', async () => {
process.env.AWS_LAMBDA_INITIALIZATION_TYPE = 'provisioned-concurrency';

initializeHandler('lambda-test/sync.handler');
const time0 = Date.now() - 1;
initializeHandler('lambda-test/sync.handler', { lambdaStartTime: time0 });

const time1 = Date.now();
const result = await new Promise((resolve, reject) => {
lambdaRequire('lambda-test/sync').handler(
'arg',
Expand All @@ -323,20 +342,26 @@ describe('lambda handler', () => {
}
);
});

assert.strictEqual(result, 'ok');
const spans = memoryExporter.getFinishedSpans();
const [span] = spans;

assert.strictEqual(spans.length, 1);
assertSpanSuccess(span);
assert.strictEqual(span.parentSpanId, undefined);
assert.strictEqual(span.attributes[SEMATTRS_FAAS_COLDSTART], false);
// Since it is warm invocation, invocation span start time should be after than lambda start time
assert.ok(hrTimeToMilliseconds(span.startTime) > time0);
// Since it is warm invocation, invocation span start time should be equal or after than handler call time
assert.ok(hrTimeToMilliseconds(span.startTime) >= time1);
});

it('should record coldstart with proactive initialization', async () => {
initializeHandler('lambda-test/sync.handler', {
lambdaStartTime: Date.now() - 2 * lambdaMaxInitInMilliseconds,
});
const time0 = Date.now() - 2 * lambdaMaxInitInMilliseconds;
initializeHandler('lambda-test/sync.handler', { lambdaStartTime: time0 });

const time1 = Date.now();
const result = await new Promise((resolve, reject) => {
lambdaRequire('lambda-test/sync').handler(
'arg',
Expand All @@ -350,13 +375,19 @@ describe('lambda handler', () => {
}
);
});

assert.strictEqual(result, 'ok');
const spans = memoryExporter.getFinishedSpans();
const [span] = spans;

assert.strictEqual(spans.length, 1);
assertSpanSuccess(span);
assert.strictEqual(span.parentSpanId, undefined);
assert.strictEqual(span.attributes[SEMATTRS_FAAS_COLDSTART], false);
// Since it is warm invocation, invocation span start time should be after than lambda start time
assert.ok(hrTimeToMilliseconds(span.startTime) > time0);
// Since it is warm invocation, invocation span start time should be equal or after than handler call time
assert.ok(hrTimeToMilliseconds(span.startTime) >= time1);
});

it('should record error', async () => {
Expand Down