From 6988d92ec5fc95f36b67f3bf053cf695b6a96c2e Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 17:38:35 +0100 Subject: [PATCH 01/15] Moved to common packages --- packages/tracing/npm-shrinkwrap.json | 10 +++----- packages/tracing/src/Tracer.ts | 20 ++++++++------- packages/tracing/tests/unit/Tracer.test.ts | 29 +++++++++++----------- 3 files changed, 30 insertions(+), 29 deletions(-) diff --git a/packages/tracing/npm-shrinkwrap.json b/packages/tracing/npm-shrinkwrap.json index cf38edaeb6..9206c799a9 100644 --- a/packages/tracing/npm-shrinkwrap.json +++ b/packages/tracing/npm-shrinkwrap.json @@ -1,16 +1,16 @@ { "name": "@aws-lambda-powertools/tracer", - "version": "0.0.0", + "version": "0.2.0-beta.0", "lockfileVersion": 2, "requires": true, "packages": { "": { "name": "@aws-lambda-powertools/tracer", - "version": "0.0.0", + "version": "0.2.0-beta.0", "license": "MIT", "dependencies": { - "@middy/core": "^2.5.3", "@aws-lambda-powertools/commons": "^0.0.2", + "@middy/core": "^2.5.3", "aws-xray-sdk-core": "^3.3.3" }, "devDependencies": { @@ -2330,8 +2330,7 @@ "esprima": "^4.0.1", "estraverse": "^5.2.0", "esutils": "^2.0.2", - "optionator": "^0.8.1", - "source-map": "~0.6.1" + "optionator": "^0.8.1" }, "bin": { "escodegen": "bin/escodegen.js", @@ -3966,7 +3965,6 @@ "@types/node": "*", "anymatch": "^3.0.3", "fb-watchman": "^2.0.0", - "fsevents": "^2.3.2", "graceful-fs": "^4.2.4", "jest-regex-util": "^27.4.0", "jest-serializer": "^27.4.0", diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 6a36efbe18..b8f1259df9 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -19,6 +19,8 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * * ## Usage * + * For more usage examples, see [our documentation](https://awslabs.github.io/aws-lambda-powertools-typescript/latest/core/tracer/). + * * ### Functions usage with middlewares * * If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: @@ -78,24 +80,24 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * const tracer = new Tracer({ serviceName: 'my-service' }); * * export const handler = async (_event: any, context: any) => { - * // Create subsegment & set it as active - * const subsegment = new Subsegment(`## ${context.functionName}`); - * tracer.setSegment(subsegment); - * // Add the ColdStart annotation + * const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) + * // Create subsegment for the function + * const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); + * // TODO: expose tracer.annotateColdStart() * this.putAnnotation('ColdStart', tracer.isColdStart()); * * let res; * try { - * res = await someLogic(); // Do something + * res = ... * // Add the response as metadata - * tracer.putMetadata(`${context.functionName} response`, data); + * tracer.putMetadata(`${context.functionName} response`, res); * } catch (err) { * // Add the error as metadata - * subsegment.addError(err, false); + * handlerSegment.addError(err as Error, false); * } * - * // Close subsegment - * subsegment.close(); + * // Close subsegment (the AWS Lambda one is closed automatically) + * handlerSegment.close(); * * return res; * } diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index 157cda7412..b6a387d706 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -1,8 +1,5 @@ -import { context as dummyContext } from '../../../../tests/resources/contexts/hello-world'; -// eslint-disable-next-line @typescript-eslint/ban-ts-comment -// @ts-ignore -import * as dummyEvent from '../../../../tests/resources/events/custom/hello-world.json'; import { LambdaInterface } from '../../examples/utils/lambda'; +import { Events, ContextExamples } from '@aws-lambda-powertools/commons'; import { Tracer } from '../../src'; import { Callback, Context } from 'aws-lambda/handler'; import { Segment, setContextMissingStrategy, Subsegment } from 'aws-xray-sdk-core'; @@ -13,6 +10,8 @@ jest.spyOn(console, 'error').mockImplementation(() => null); describe('Class: Tracer', () => { const ENVIRONMENT_VARIABLES = process.env; + const event = Events.Custom.CustomEvent; + const context = ContextExamples.helloworldContext; beforeEach(() => { Tracer.coldStart = true; @@ -348,7 +347,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(Events.Custom.CustomEvent, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(0); @@ -378,7 +377,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); @@ -410,7 +409,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); @@ -452,7 +451,7 @@ describe('Class: Tracer', () => { } // Act & Assess - await expect(new Lambda().handler({}, dummyContext, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); + await expect(new Lambda().handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); expect(newSubsegment).toEqual(expect.objectContaining({ name: '## foo-bar-function', @@ -488,7 +487,7 @@ describe('Class: Tracer', () => { } // Act & Assess - await expect(new Lambda().handler({}, dummyContext, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); + await expect(new Lambda().handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); expect(newSubsegment).toEqual(expect.objectContaining({ name: '## foo-bar-function', @@ -526,8 +525,8 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(2); @@ -559,6 +558,8 @@ describe('Class: Tracer', () => { // TODO: revisit return type & make it more specific @tracer.captureMethod() + // eslint-disable-next-line @typescript-eslint/ban-ts-comment + // @ts-ignore // eslint-disable-next-line @typescript-eslint/no-explicit-any public async dummyMethod(some: string): Promise { return new Promise((resolve, _reject) => resolve(some)); @@ -573,7 +574,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toBeCalledTimes(0); @@ -607,7 +608,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); @@ -651,7 +652,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); From 14c55839547377c228a0f5a521ba32211a0bdd34 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 17:39:06 +0100 Subject: [PATCH 02/15] Updated docs --- packages/tracing/README.md | 980 +++---------------------------------- 1 file changed, 68 insertions(+), 912 deletions(-) diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 9e1f093a15..c1ed511909 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -1,935 +1,91 @@ # `tracer` -## Usage - -```bash - -npm run test - -npm run example:hello-world -npm run example:capture-lambda-handler-response-decorator -npm run example:capture-lambda-handler-error-decorator - -``` - -### Getting started - -```typescript -// Import the library -import { Tracer } from "../src"; -// When going public, it will be something like: import { Tracer } from '@aws-lambda-powertools/tracer'; - -// Environment variables set for the Lambda -process.env.POWERTOOLS_TRACE_ENABLED = "true"; -process.env.POWERTOOLS_SERVICE_NAME = "hello-world"; -process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = "true"; -process.env.POWERTOOLS_TRACER_CAPTURE_ERROR = "true"; - -// Instantiate the Tracer with default configuration -const tracer = new Tracer(); -``` - -### Capturing Lambda handler - -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - return new Promise((resolve, _reject) => resolve({ - foo: 'bar' - } as unknown as TResult)); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "annotations": { - "ColdStart": true - }, - "metadata": { - "hello-world": { - "foo-bar-function response": { - "foo": "bar" - } - } - } - } - ] - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
- -**With Error** -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - // Some logic that throws an error - throw Error('Some error occurred') - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "fault": true, - "cause": { - "working_directory": "/var/task", - "exceptions": [ - { - "message": "Some error occurred", - "type": "Error", - "remote": false, - "stack": [ - { - "path": "/var/task/index.js", - "line": 51489, - "label": "Tracer2.handler" - }, - { - "path": "/var/task/index.js", - "line": 16372, - "label": "anonymous" - }, - // Full stack trace - ] - } - ] - } - } - ] - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
+Tracer is an opinionated thin wrapper for [AWS X-Ray SDK for Node.js](https://github.com/aws/aws-xray-sdk-node). -### Adding annotation on subsegment - -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - tracer.putAnnotation("my-annotation", "my-value"); - - return new Promise((resolve, _reject) => resolve({ - foo: 'bar' - } as unknown as TResult)); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "annotations": { - "ColdStart": true, - "my-annotation": "my-value" - }, - "metadata": { - "hello-world": { - "foo-bar-function response": { - "foo": "bar" - } - } - } - } - ] - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
- -### Adding metadata to subsegment - -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - tracer.putMetadata("my-metadata", 1234); - tracer.putMetadata("my-scoped-metadata", 1234, "my-namespace"); - - return new Promise((resolve, _reject) => resolve({ - foo: 'bar' - } as unknown as TResult)); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "annotations": { - "ColdStart": true - }, - "metadata": { - "hello-world": { - "foo-bar-function response": { - "foo": "bar" - }, - "my-metadata": 1234 - }, - "my-namespace": { - "my-scoped-metadata": 1234 - } - } - } - ] - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
- -### Capturing other methods - -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - @tracer.captureMethod() - public async dummyMethod(some: string): Promise { - // Some async logic - return new Promise((resolve, _reject) => setTimeout(() => resolve(some), 3000)); - } - - public async handler(_event: TEvent, _context: Context, _callback: Callback): Promise { - const result = await this.dummyMethod('bar'); - - return new Promise((resolve, _reject) => resolve({ - foo: result - } as unknown as TResult)); - } - -} +Tracing data can be visualized through AWS X-Ray Console. -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); +## Key features +* Auto capture cold start as annotation, and responses or full exceptions as metadata +* Auto-disable when not running in AWS Lambda environment +* Support tracing functions via decorators, middleware, and manual instrumentation +* Support tracing AWS SDK v2 and v3 via AWS X-Ray SDK for Node.js -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "annotations": { - "ColdStart": true - }, - "subsegments": [ - { - "id": "b1ac78c231577476", - "name": "### dummyMethod", - "start_time": 1638845552.777, - "end_time": 1638845553.459, - "metadata": { - "hello-world": { - "dummyMethod response": "bar" - } - // Other metadata (if any) - } - // Annotations (if any) - // Other subsegments (if any) - } - ] - } - ] - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
- -### Capturing AWS SDK clients - -**AWS SDK JS v3** -```typescript -// AWS SDK JS v3 -import { S3Client, ListObjectsV2Command } from "@aws-sdk/client-s3"; -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); -const client = new S3Client({}); -tracer.captureAWSv3Client(client); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - const command = new ListObjectsV2Command({ - Bucket: process.env.BUCKET_NAME, - }); - - return client - .send(command) - .then((data) => { - // Do something with data - - return { - foo: "bar", - } as unknown as TResult; - }) - .catch((error) => { - logger.error("Error from action", error); - }); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -**AWS SDK JS v2 (specific client)** - -```typescript -// AWS SDK JS v2 -import { S3 } from "aws-sdk"; -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); -const client = tracer.captureAWSClient(new S3({ apiVersion: "2006-03-01" })); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - return s3 - .listObjectsV2({ - Bucket: process.env.BUCKET_NAME || "", - }) - .promise() - .then((data) => { - // Do something with data - - return { - foo: "bar", - } as unknown as TResult; - }) - .catch((error) => { - logger.error("Error from action", error); - }); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -**AWS SDK JS v2 (all clients)** - -```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); -// Capture all AWS SDK clients -const AWS = tracer.captureAWS(require('aws-sdk')); -const s3 = new AWS.S3({ apiVersion: "2006-03-01" }); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - return s3 - .listObjectsV2({ - Bucket: process.env.BUCKET_NAME || "", - }) - .promise() - .then((data: unknown) => { - // Do something with data - - return { - foo: "bar", - } as unknown as TResult; - }) - .catch((error: Error) => { - logger.error("Error from action", error); - }); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "metadata": { - // Handler segment metadata - }, - "subsegments": [ - { - "id": "aae0c94a16d66abd", - "name": "## foo-bar-function", - "start_time": 1638792392.766, - "end_time": 1638792392.836, - "http": { - "response": { - "status": 200 - } - }, - "aws": { - "retries": 1, - "region": "eu-west-1", - "operation": "ListObjectsV2", - "id_2": "mmG8kljASOkl9t5TsBd4D//U5W7Dr1ZrLWEsajtNMqY+VGLFDp0OHpYLz670ETOBPWERFyYh2w0=" - }, - "namespace": "aws" - } - ] - }, - // Overhead subsegment (if any) - ] - } - }, - { - "Id": "021345abcdef6789", - "Document": { - "id": "021345abcdef6789", - "name": "foo-bar-function", - "start_time": 1638800791.846, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638800793.349, - "http": { - "response": { - "status": 200 - } - }, - "aws": { - "request_id": "27df07c5-1c35-42eb-ae6f-55193c404205" - }, - "origin": "AWS::Lambda", - "resource_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - } - }, - { - "Id": "117e4d4e091318a3", - "Document": { - "id": "117e4d4e091318a3", - "name": "S3", - "start_time": 1638800792.61, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638800793.247, - "parent_id": "1234567890abcdef0", - "inferred": true, - "http": { - "response": { - "status": 200 - } - }, - "aws": { - "retries": 1, - "region": "eu-west-1", - "operation": "ListObjectsV2", - "id_2": "mmG8kljASOkl9t5TsBd4D//U5W7Dr1ZrLWEsajtNMqY+VGLFDp0OHpYLz670ETOBPWERFyYh2w0=" - }, - "origin": "AWS::S3" - } - } - ] -} +## Usage -``` -
+For more usage examples, see [our documentation](https://awslabs.github.io/aws-lambda-powertools-typescript/latest/core/tracer/). -### Disabling capture response body +### Functions usage with middlewares +If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: +* handle the subsegment lifecycle +* add the `ColdStart` annotation +* add the function response as metadata +* add the function error as metadata (if any) + ```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; -process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = 'false'; - -const tracer = new Tracer(); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - - return new Promise((resolve, _reject) => resolve({ - foo: 'bar' - } as unknown as TResult)); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - +import { Tracer, captureLambdaHandler } from '@aws-lambda-powertools/tracer'; +import middy from '@middy/core'; + +const tracer = new Tracer({ serviceName: 'my-service' }); + +export const handler = middy(async (_event: any, _context: any) => { + ... +}).use(captureLambdaHandler(tracer)); ``` -
- Click to expand and see the trace +### Object oriented usage with decorators -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - } - // Annotations (if any) - // Other metadata (if any) - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
- -### Disabling capture error +If instead you use TypeScript Classes to wrap your Lambda handler you can use the [@tracer.captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html#captureLambdaHanlder) decorator to automatically: +* handle the subsegment lifecycle +* add the `ColdStart` annotation +* add the function response as metadata +* add the function error as metadata (if any) ```typescript -// Environment variables set for the Lambda -process.env.POWERTOOLS_TRACER_CAPTURE_ERROR = "false"; -process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; - -const tracer = new Tracer(); +import { Tracer } from '@aws-lambda-powertools/tracer'; -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - // Some logic that throws an error - throw Error('Some error occurred') - } +const tracer = new Tracer({ serviceName: 'my-service' }); +class Lambda { + @tracer.captureLambdaHanlder() + public handler(event: any, context: any) { + ... + } } -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - +export const handlerClass = new Lambda(); +export const handler = handlerClass.handler; ``` -
- Click to expand and see the trace - -```json -{ - "Id": "abcdef123456abcdef123456abcdef123456", - "Duration": 0.656, - "LimitExceeded": false, - "Segments": [ - { - "Id": "1234567890abcdef0", - "Document": { - "id": "1234567890abcdef0", - "name": "foo-bar-function", - "start_time": 1638792392.764036, - "trace_id": "abcdef123456abcdef123456abcdef123456", - "end_time": 1638792392.957155, - "parent_id": "abcdef01234567890", - "aws": { - "account_id": "111122223333", - "function_arn": "arn:aws:lambda:us-east-1:111122223333:function:foo-bar-function", - "resource_names": [ - "foo-bar-function" - ] - }, - "origin": "AWS::Lambda::Function", - "subsegments": [ - // Initialization subsegment (if any) - { - "id": "4be0933d48d5b52f", - "name": "Invocation", - "start_time": 1638792392.7642102, - "end_time": 1638792392.9384046, - "aws": { - "function_arn": "arn:aws:lambda:eu-west-1:111122223333:function:foo-bar-function" - }, - "error": true, - // Annotations (if any) - // Other metadata (if any) - }, - // Overhead subsegment (if any) - ] - } - } - ] -} - -``` -
+### Functions usage with manual instrumentation -## Constructor options +If you prefer to manually instrument your Lambda handler you can use the methods in the tracer class directly. ```typescript - -const tracer = new Tracer({ - enabled: true, - serviceName: 'hello-world' -}); - -class Lambda implements LambdaInterface { - - @tracer.captureLambdaHanlder() - public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { - return new Promise((resolve, _reject) => resolve({ - foo: 'bar' - } as unknown as TResult)); - } - -} - -new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!')); - -``` - -
- Click to expand and see the logs outputs - -```bash - -{ - level: 'INFO', - message: 'This is an INFO log', - sampling_rate: 0.5, - service: 'hello-world', - timestamp: '2021-03-25T09:59:31.252Z', - xray_trace_id: 'abcdef123456abcdef123456abcdef123456', - awsAccountId: '123456789012', - logger: { name: 'aws-lambda-powertools-typescript', version: '0.0.1' }, - correlationIds: { myCustomCorrelationId: 'foo-bar-baz' } -} - -``` - -
\ No newline at end of file +import { Tracer } from '@aws-lambda-powertools/tracer'; + +const tracer = new Tracer({ serviceName: 'my-service' }); + +export const handler = async (_event: any, context: any) => { + const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) + // Create subsegment for the function + const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); + // TODO: expose tracer.annotateColdStart() + this.putAnnotation('ColdStart', tracer.isColdStart()); + + let res; + try { + res = ... + // Add the response as metadata + tracer.putMetadata(`${context.functionName} response`, res); + } catch (err) { + // Add the error as metadata + handlerSegment.addError(err as Error, false); + } + + // Close subsegment (the AWS Lambda one is closed automatically) + handlerSegment.close(); + + return res; +} +``` \ No newline at end of file From 35c4c3daf1b6929c0bee4ac50f2b61f5c9167b2b Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 17:39:40 +0100 Subject: [PATCH 03/15] Update main docs --- docs/core/tracer.md | 27 +++++++++++++-------------- 1 file changed, 13 insertions(+), 14 deletions(-) diff --git a/docs/core/tracer.md b/docs/core/tracer.md index 7fc1ab031e..625b3dbec7 100644 --- a/docs/core/tracer.md +++ b/docs/core/tracer.md @@ -75,32 +75,31 @@ You can quickly start by importing the `Tracer` class, initialize it outside the === "Manual" - ```typescript hl_lines="1-2 4 9-10 12 18 21 25" + ```typescript hl_lines="1 3 7 9 11 17 20 24" import { Tracer } from '@aws-lambda-powertools/tracer'; - import { Segment } from 'aws-xray-sdk-core'; const tracer = Tracer(); // Sets service via env var // OR tracer = Tracer({ service: 'example' }); export const handler = async (_event: any, context: any) => { - // Create subsegment & set it as active - const subsegment = new Subsegment(`## ${context.functionName}`); - tracer.setSegment(subsegment); - // Add the ColdStart annotation - this.putAnnotation('ColdStart', tracer.coldStart); + const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) + // Create subsegment for the function + const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); + // TODO: expose tracer.annotateColdStart() + this.putAnnotation('ColdStart', tracer.isColdStart()); let res; try { - res = await someLogic(); // Do something - // Add the response as metadata - tracer.putMetadata(`${context.functionName} response`, data); + res = ... + // Add the response as metadata + tracer.putMetadata(`${context.functionName} response`, res); } catch (err) { // Add the error as metadata - subsegment.addError(err, false); + handlerSegment.addError(err as Error, false); } - - // Close subsegment - subsegment.close(); + + // Close subsegment (the AWS Lambda one is closed automatically) + handlerSegment.close(); return res; } From 162c1d7177e4c48c9db5e5144209110c35980f2c Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 18:03:09 +0100 Subject: [PATCH 04/15] Exposed addResponseAsMetadata --- docs/core/tracer.md | 2 +- packages/tracing/README.md | 2 +- packages/tracing/src/Tracer.ts | 47 ++++++---------- packages/tracing/src/middleware/middy.ts | 7 +-- packages/tracing/tests/unit/Tracer.test.ts | 63 ++++++++++++++++++++++ 5 files changed, 84 insertions(+), 37 deletions(-) diff --git a/docs/core/tracer.md b/docs/core/tracer.md index 625b3dbec7..93fd36ab45 100644 --- a/docs/core/tracer.md +++ b/docs/core/tracer.md @@ -92,7 +92,7 @@ You can quickly start by importing the `Tracer` class, initialize it outside the try { res = ... // Add the response as metadata - tracer.putMetadata(`${context.functionName} response`, res); + tracer.addResponseAsMetadata(res, context.functionName); } catch (err) { // Add the error as metadata handlerSegment.addError(err as Error, false); diff --git a/packages/tracing/README.md b/packages/tracing/README.md index c1ed511909..18eda12aad 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -77,7 +77,7 @@ export const handler = async (_event: any, context: any) => { try { res = ... // Add the response as metadata - tracer.putMetadata(`${context.functionName} response`, res); + tracer.addResponseAsMetadata(res, context.functionName); } catch (err) { // Add the error as metadata handlerSegment.addError(err as Error, false); diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index b8f1259df9..c885033299 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -90,7 +90,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * try { * res = ... * // Add the response as metadata - * tracer.putMetadata(`${context.functionName} response`, res); + * tracer.addResponseAsMetadata(res, context.functionName); * } catch (err) { * // Add the error as metadata * handlerSegment.addError(err as Error, false); @@ -125,6 +125,22 @@ class Tracer implements TracerInterface { this.provider = new ProviderService(); } + /** + * Add an data to the current segment or subsegment as metadata. + * + * @see https://docs.aws.amazon.com/xray/latest/devguide/xray-concepts.html#xray-concepts-annotations + * + * @param data - Data to serialize as metadata + * @param methodName - Name of the method that is being traced + */ + public addResponseAsMetadata(data?: unknown, methodName?: string): void { + if (data === undefined || this.captureResponse === false || this.tracingEnabled === false) { + return; + } + + this.putMetadata(`${methodName} response`, data); + } + /** * Patch all AWS SDK v2 clients and create traces when your application makes calls to AWS services. * @@ -382,18 +398,6 @@ class Tracer implements TracerInterface { return this.captureError; } - /** - * Get the current value of the `captureResponse` property. - * - * You can use this method during manual instrumentation to determine - * if tracer should be capturing function responses. - * - * @returns captureResponse - `true` if responses should be captured, `false` otherwise. - */ - public isCaptureResponseEnabled(): boolean { - return this.captureResponse; - } - /** * Retrieve the current value of `ColdStart`. * @@ -537,23 +541,6 @@ class Tracer implements TracerInterface { subsegment.addError(error, false); } - - /** - * Add an data to the current segment or subsegment as metadata. - * Used internally by decoratorators and middlewares. - * - * @see https://docs.aws.amazon.com/xray/latest/devguide/xray-concepts.html#xray-concepts-errors - * - * @param data - Data to serialize as metadata - * @param methodName - Name of the method that is being traced - */ - private addResponseAsMetadata(data?: unknown, methodName?: string): void { - if (data === undefined || this.captureResponse === false || this.tracingEnabled === false) { - return; - } - - this.putMetadata(`${methodName} response`, data); - } /** * Add ColdStart annotation to the current segment or subsegment. diff --git a/packages/tracing/src/middleware/middy.ts b/packages/tracing/src/middleware/middy.ts index 79a37b18d0..9022e34dbd 100644 --- a/packages/tracing/src/middleware/middy.ts +++ b/packages/tracing/src/middleware/middy.ts @@ -41,11 +41,8 @@ const captureLambdaHandler = (target: Tracer): middy.MiddlewareObj => { const captureLambdaHandlerAfter = async (request: middy.Request): Promise => { if (target.isTracingEnabled()) { const subsegment = target.getSegment(); - if (request.response !== undefined && target.isCaptureResponseEnabled() === true) { - target.putMetadata(`${request.context.functionName} response`, request.response); - } - - subsegment?.close(); + target.addResponseAsMetadata(request.response, request.context.functionName); + subsegment.close(); } }; diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index b6a387d706..effdd5a377 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -24,6 +24,69 @@ describe('Class: Tracer', () => { process.env = ENVIRONMENT_VARIABLES; }); + describe('Method: addResponseAsMetadata', () => { + + test('when called while tracing is disabled, it does nothing', () => { + + // Prepare + const tracer: Tracer = new Tracer({ enabled: false }); + const putMetadataSpy = jest.spyOn(tracer, 'putMetadata'); + + // Act + tracer.addResponseAsMetadata({ foo: 'bar' }, context.functionName); + + // Assess + expect(putMetadataSpy).toBeCalledTimes(0); + + }); + + test('when called while POWERTOOLS_TRACER_CAPTURE_RESPONSE is set to false, it does nothing', () => { + + // Prepare + process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = 'false'; + const tracer: Tracer = new Tracer(); + const putMetadataSpy = jest.spyOn(tracer, 'putMetadata'); + + // Act + tracer.addResponseAsMetadata({ foo: 'bar' }, context.functionName); + + // Assess + expect(putMetadataSpy).toBeCalledTimes(0); + delete process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE; + + }); + + test('when called with data equal to undefined, it does nothing', () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const putMetadataSpy = jest.spyOn(tracer, 'putMetadata'); + + // Act + tracer.addResponseAsMetadata(undefined, context.functionName); + + // Assess + expect(putMetadataSpy).toBeCalledTimes(0); + + }); + + test('when called with default config, it calls tracer.putMetadata correctly', () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const putMetadataSpy = jest.spyOn(tracer, 'putMetadata').mockImplementation(() => null); + + // Act + tracer.addResponseAsMetadata({ foo: 'bar' }, context.functionName); + + // Assess + expect(putMetadataSpy).toBeCalledTimes(1); + expect(putMetadataSpy).toBeCalledWith(`${context.functionName} response`, expect.objectContaining({ foo: 'bar' })); + + }); + + }); + describe('Method: isColdStart', () => { test('when called, it returns false the first time and always true after that', () => { From 57bf02d70bc6e77fc150e8e9430bf4ed44245efa Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 18:15:38 +0100 Subject: [PATCH 05/15] Exposed addErrorAsMetadata --- docs/core/tracer.md | 2 +- packages/tracing/README.md | 2 +- packages/tracing/src/Tracer.ts | 55 +++++++++------------ packages/tracing/src/middleware/middy.ts | 7 +-- packages/tracing/tests/unit/Tracer.test.ts | 57 ++++++++++++++++++++++ 5 files changed, 84 insertions(+), 39 deletions(-) diff --git a/docs/core/tracer.md b/docs/core/tracer.md index 93fd36ab45..06d307cc00 100644 --- a/docs/core/tracer.md +++ b/docs/core/tracer.md @@ -95,7 +95,7 @@ You can quickly start by importing the `Tracer` class, initialize it outside the tracer.addResponseAsMetadata(res, context.functionName); } catch (err) { // Add the error as metadata - handlerSegment.addError(err as Error, false); + tracer.addErrorAsMetadata(err as Error); } // Close subsegment (the AWS Lambda one is closed automatically) diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 18eda12aad..61a3a0932d 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -80,7 +80,7 @@ export const handler = async (_event: any, context: any) => { tracer.addResponseAsMetadata(res, context.functionName); } catch (err) { // Add the error as metadata - handlerSegment.addError(err as Error, false); + tracer.addErrorAsMetadata(err as Error); } // Close subsegment (the AWS Lambda one is closed automatically) diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index c885033299..4fbb4abe4a 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -93,7 +93,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * tracer.addResponseAsMetadata(res, context.functionName); * } catch (err) { * // Add the error as metadata - * handlerSegment.addError(err as Error, false); + * tracer.addErrorAsMetadata(err as Error); * } * * // Close subsegment (the AWS Lambda one is closed automatically) @@ -125,6 +125,28 @@ class Tracer implements TracerInterface { this.provider = new ProviderService(); } + /** + * Add an error to the current segment or subsegment as metadata. + * + * @see https://docs.aws.amazon.com/xray/latest/devguide/xray-concepts.html#xray-concepts-errors + * + * @param error - Error to serialize as metadata + */ + public addErrorAsMetadata(error: Error): void { + if (this.tracingEnabled === false) { + return; + } + + const subsegment = this.getSegment(); + if (this.captureError === false) { + subsegment.addErrorFlag(); + + return; + } + + subsegment.addError(error, false); + } + /** * Add an data to the current segment or subsegment as metadata. * @@ -385,18 +407,6 @@ class Tracer implements TracerInterface { return segment; } - - /** - * Get the current value of the `captureError` property. - * - * You can use this method during manual instrumentation to determine - * if tracer should be capturing errors. - * - * @returns captureError - `true` if errors should be captured, `false` otherwise. - */ - public isCaptureErrorEnabled(): boolean { - return this.captureError; - } /** * Retrieve the current value of `ColdStart`. @@ -522,25 +532,6 @@ class Tracer implements TracerInterface { public setSegment(segment: Segment | Subsegment): void { return this.provider.setSegment(segment); } - - /** - * Add an error to the current segment or subsegment as metadata. - * Used internally by decoratorators and middlewares. - * - * @see https://docs.aws.amazon.com/xray/latest/devguide/xray-concepts.html#xray-concepts-errors - * - * @param error - Error to serialize as metadata - */ - private addErrorAsMetadata(error: Error): void { - const subsegment = this.getSegment(); - if (this.captureError === false) { - subsegment.addErrorFlag(); - - return; - } - - subsegment.addError(error, false); - } /** * Add ColdStart annotation to the current segment or subsegment. diff --git a/packages/tracing/src/middleware/middy.ts b/packages/tracing/src/middleware/middy.ts index 9022e34dbd..afbe8a373f 100644 --- a/packages/tracing/src/middleware/middy.ts +++ b/packages/tracing/src/middleware/middy.ts @@ -49,11 +49,8 @@ const captureLambdaHandler = (target: Tracer): middy.MiddlewareObj => { const captureLambdaHandlerError = async (request: middy.Request): Promise => { if (target.isTracingEnabled()) { const subsegment = target.getSegment(); - if (target.isCaptureErrorEnabled() === false) { - subsegment?.addErrorFlag(); - } else { - subsegment?.addError(request.error as Error, false); - } + target.addErrorAsMetadata(request.error as Error); + // TODO: should this error be thrown?? I.e. should we stop the event flow & return? // throw request.error; diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index effdd5a377..f0ae79535e 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -87,6 +87,63 @@ describe('Class: Tracer', () => { }); + describe('Method: addErrorAsMetadata', () => { + + test('when called while tracing is disabled, it does nothing', () => { + + // Prepare + const tracer: Tracer = new Tracer({ enabled: false }); + const getSegmentSpy = jest.spyOn(tracer, 'getSegment'); + + // Act + tracer.addErrorAsMetadata(new Error('foo')); + + // Assess + expect(getSegmentSpy).toBeCalledTimes(0); + + }); + + test('when called while POWERTOOLS_TRACER_CAPTURE_ERROR is set to false, it does not capture the error', () => { + + // Prepare + process.env.POWERTOOLS_TRACER_CAPTURE_ERROR = 'false'; + const tracer: Tracer = new Tracer(); + const subsegment = new Subsegment(`## ${context.functionName}`); + jest.spyOn(tracer, 'getSegment').mockImplementation(() => subsegment); + const addErrorFlagSpy = jest.spyOn(subsegment, 'addErrorFlag'); + const addErrorSpy = jest.spyOn(subsegment, 'addError'); + + // Act + tracer.addErrorAsMetadata(new Error('foo')); + + // Assess + expect(addErrorFlagSpy).toBeCalledTimes(1); + expect(addErrorSpy).toBeCalledTimes(0); + delete process.env.POWERTOOLS_TRACER_CAPTURE_ERROR; + + }); + + test('when called with default config, it calls subsegment.addError correctly', () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const subsegment = new Subsegment(`## ${context.functionName}`); + jest.spyOn(tracer, 'getSegment').mockImplementation(() => subsegment); + const addErrorFlagSpy = jest.spyOn(subsegment, 'addErrorFlag'); + const addErrorSpy = jest.spyOn(subsegment, 'addError'); + + // Act + tracer.addErrorAsMetadata(new Error('foo')); + + // Assess + expect(addErrorFlagSpy).toBeCalledTimes(0); + expect(addErrorSpy).toBeCalledTimes(1); + expect(addErrorSpy).toBeCalledWith(new Error('foo'), false); + + }); + + }); + describe('Method: isColdStart', () => { test('when called, it returns false the first time and always true after that', () => { From de86d97d0941ddf4df36ce62b03e240650872cc8 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 19:11:08 +0100 Subject: [PATCH 06/15] Exposed annotateColdStarted --- docs/core/tracer.md | 3 +- packages/tracing/README.md | 3 +- packages/tracing/src/Tracer.ts | 75 ++++++++++++---------- packages/tracing/src/middleware/middy.ts | 5 +- packages/tracing/tests/unit/Tracer.test.ts | 46 +++++++++++-- 5 files changed, 86 insertions(+), 46 deletions(-) diff --git a/docs/core/tracer.md b/docs/core/tracer.md index 06d307cc00..2fb636b401 100644 --- a/docs/core/tracer.md +++ b/docs/core/tracer.md @@ -85,8 +85,7 @@ You can quickly start by importing the `Tracer` class, initialize it outside the const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) // Create subsegment for the function const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); - // TODO: expose tracer.annotateColdStart() - this.putAnnotation('ColdStart', tracer.isColdStart()); + tracer.annotateColdStart() let res; try { diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 61a3a0932d..41cde322b4 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -70,8 +70,7 @@ export const handler = async (_event: any, context: any) => { const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) // Create subsegment for the function const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); - // TODO: expose tracer.annotateColdStart() - this.putAnnotation('ColdStart', tracer.isColdStart()); + tracer.annotateColdStart() let res; try { diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 4fbb4abe4a..409923b965 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -83,8 +83,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) * // Create subsegment for the function * const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); - * // TODO: expose tracer.annotateColdStart() - * this.putAnnotation('ColdStart', tracer.isColdStart()); + * tracer.annotateColdStart() * * let res; * try { @@ -104,6 +103,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * ``` */ class Tracer implements TracerInterface { + public static coldStart: boolean = true; public provider: ProviderServiceInterface; @@ -163,6 +163,25 @@ class Tracer implements TracerInterface { this.putMetadata(`${methodName} response`, data); } + /** + * Add ColdStart annotation to the current segment or subsegment. + * + * If Tracer has been initialized outside of the Lambda handler then the same instance + * of Tracer will be reused throghout the lifecycle of that same Lambda execution environment + * and this method will return `false` after the first invocation. + * + * @see https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html + */ + public annotateColdStart(): void { + if (Tracer.coldStart === true) { + Tracer.coldStart = false; + + if (this.tracingEnabled === true) { + this.putAnnotation('ColdStart', true); + } + } + } + /** * Patch all AWS SDK v2 clients and create traces when your application makes calls to AWS services. * @@ -376,6 +395,27 @@ class Tracer implements TracerInterface { return descriptor; }; } + + /** + * Retrieve the current value of `ColdStart`. + * + * If Tracer has been initialized outside of the Lambda handler then the same instance + * of Tracer will be reused throghout the lifecycle of that same Lambda execution environment + * and this method will return `false` after the first invocation. + * + * @see https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html + * + * @returns boolean - `true` if is cold start, otherwise `false` + */ + public static getColdStart(): boolean { + if (Tracer.coldStart === true) { + Tracer.coldStart = false; + + return true; + } + + return false; + } /** * Get the active segment or subsegment in the current scope. @@ -408,27 +448,6 @@ class Tracer implements TracerInterface { return segment; } - /** - * Retrieve the current value of `ColdStart`. - * - * If Tracer has been initialized outside of the Lambda handler then the same instance - * of Tracer will be reused throghout the lifecycle of that same Lambda execution environment - * and this method will return `false` after the first invocation. - * - * @see https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html - * - * @returns boolean - `true` if is cold start, otherwise `false` - */ - public static isColdStart(): boolean { - if (Tracer.coldStart === true) { - Tracer.coldStart = false; - - return true; - } - - return false; - } - /** * Get the current value of the `tracingEnabled` property. * @@ -532,16 +551,6 @@ class Tracer implements TracerInterface { public setSegment(segment: Segment | Subsegment): void { return this.provider.setSegment(segment); } - - /** - * Add ColdStart annotation to the current segment or subsegment. - * Used internally by decoratorators and middlewares. - */ - private annotateColdStart(): void { - if (Tracer.isColdStart()) { - this.putAnnotation('ColdStart', true); - } - } /** * Getter for `customConfigService`. diff --git a/packages/tracing/src/middleware/middy.ts b/packages/tracing/src/middleware/middy.ts index afbe8a373f..58c9dd1d43 100644 --- a/packages/tracing/src/middleware/middy.ts +++ b/packages/tracing/src/middleware/middy.ts @@ -31,10 +31,7 @@ const captureLambdaHandler = (target: Tracer): middy.MiddlewareObj => { if (target.isTracingEnabled()) { const subsegment = new Subsegment(`## ${request.context.functionName}`); target.setSegment(subsegment); - - if (Tracer.isColdStart()) { - target.putAnnotation('ColdStart', true); - } + target.annotateColdStart(); } }; diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index f0ae79535e..3d08c08dcd 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -24,6 +24,42 @@ describe('Class: Tracer', () => { process.env = ENVIRONMENT_VARIABLES; }); + describe('Method: annotateColdStart', () => { + + test('when called while tracing is disabled, it does nothing', () => { + + // Prepare + const tracer: Tracer = new Tracer({ enabled: false }); + const putAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); + + // Act + tracer.annotateColdStart(); + + // Assess + expect(putAnnotationSpy).toBeCalledTimes(0); + + }); + + test('when called multiple times, it annotates the first time and then never again', () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const putAnnotationSpy = jest.spyOn(tracer, 'putAnnotation').mockImplementation(() => null); + + // Act + tracer.annotateColdStart(); + tracer.annotateColdStart(); + tracer.annotateColdStart(); + tracer.annotateColdStart(); + + // Assess + expect(putAnnotationSpy).toBeCalledTimes(1); + expect(putAnnotationSpy).toBeCalledWith('ColdStart', true); + + }); + + }); + describe('Method: addResponseAsMetadata', () => { test('when called while tracing is disabled, it does nothing', () => { @@ -144,15 +180,15 @@ describe('Class: Tracer', () => { }); - describe('Method: isColdStart', () => { + describe('Method: getColdStart', () => { test('when called, it returns false the first time and always true after that', () => { // Assess - expect(Tracer.isColdStart()).toBe(true); - expect(Tracer.isColdStart()).toBe(false); - expect(Tracer.isColdStart()).toBe(false); - expect(Tracer.isColdStart()).toBe(false); + expect(Tracer.getColdStart()).toBe(true); + expect(Tracer.getColdStart()).toBe(false); + expect(Tracer.getColdStart()).toBe(false); + expect(Tracer.getColdStart()).toBe(false); }); From 0763143a44c226fad2b93fad4ebc085112e5bb7c Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 19:19:59 +0100 Subject: [PATCH 07/15] Feature parity w/ Python #851 --- packages/tracing/src/Tracer.ts | 7 +++--- packages/tracing/tests/unit/Tracer.test.ts | 25 ++++++++++++++++------ packages/tracing/tests/unit/middy.test.ts | 14 ++++++++---- 3 files changed, 31 insertions(+), 15 deletions(-) diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 409923b965..0e28180f9f 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -173,12 +173,11 @@ class Tracer implements TracerInterface { * @see https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html */ public annotateColdStart(): void { + if (this.tracingEnabled === true) { + this.putAnnotation('ColdStart', Tracer.coldStart); + } if (Tracer.coldStart === true) { Tracer.coldStart = false; - - if (this.tracingEnabled === true) { - this.putAnnotation('ColdStart', true); - } } } diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index 3d08c08dcd..8894055f89 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -40,7 +40,7 @@ describe('Class: Tracer', () => { }); - test('when called multiple times, it annotates the first time and then never again', () => { + test('when called multiple times, it annotates true the first time and then false afterwards', () => { // Prepare const tracer: Tracer = new Tracer(); @@ -53,8 +53,13 @@ describe('Class: Tracer', () => { tracer.annotateColdStart(); // Assess - expect(putAnnotationSpy).toBeCalledTimes(1); - expect(putAnnotationSpy).toBeCalledWith('ColdStart', true); + expect(putAnnotationSpy).toBeCalledTimes(4); + expect(putAnnotationSpy.mock.calls).toEqual([ + [ 'ColdStart', true ], + [ 'ColdStart', false ], + [ 'ColdStart', false ], + [ 'ColdStart', false ], + ]); }); @@ -666,7 +671,7 @@ describe('Class: Tracer', () => { .mockImplementation(() => newSubsegmentSecondInvocation); setContextMissingStrategy(() => null); const captureAsyncFuncSpy = jest.spyOn(tracer.provider, 'captureAsyncFunc'); - const addAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); + const putAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); class Lambda implements LambdaInterface { @tracer.captureLambdaHanlder() @@ -687,8 +692,11 @@ describe('Class: Tracer', () => { // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(2); expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); - expect(addAnnotationSpy).toHaveBeenCalledTimes(1); - expect(addAnnotationSpy).toHaveBeenCalledWith('ColdStart', true); + expect(putAnnotationSpy).toHaveBeenCalledTimes(2); + expect(putAnnotationSpy.mock.calls).toEqual([ + [ 'ColdStart', true ], + [ 'ColdStart', false ], + ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', annotations: { @@ -696,7 +704,10 @@ describe('Class: Tracer', () => { } })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function' + name: '## foo-bar-function', + annotations: { + 'ColdStart': false, + } })); }); diff --git a/packages/tracing/tests/unit/middy.test.ts b/packages/tracing/tests/unit/middy.test.ts index adef075f66..944c3b354f 100644 --- a/packages/tracing/tests/unit/middy.test.ts +++ b/packages/tracing/tests/unit/middy.test.ts @@ -216,7 +216,7 @@ describe('Middy middlewares', () => { .mockImplementationOnce(() => newSubsegmentFirstInvocation) .mockImplementation(() => newSubsegmentSecondInvocation); setContextMissingStrategy(() => null); - const addAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); + const putAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); const lambdaHandler: Handler = async (_event: unknown, _context: Context) => ({ foo: 'bar' }); @@ -232,8 +232,11 @@ describe('Middy middlewares', () => { expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ name: '## foo-bar-function', })); - expect(addAnnotationSpy).toHaveBeenCalledTimes(1); - expect(addAnnotationSpy).toHaveBeenCalledWith('ColdStart', true); + expect(putAnnotationSpy).toHaveBeenCalledTimes(2); + expect(putAnnotationSpy.mock.calls).toEqual([ + [ 'ColdStart', true ], + [ 'ColdStart', false ], + ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', annotations: { @@ -241,7 +244,10 @@ describe('Middy middlewares', () => { } })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function' + name: '## foo-bar-function', + annotations: { + 'ColdStart': false, + } })); }); From 019655c98d73cfa9a941f21b7c829d6c15af765c Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Fri, 17 Dec 2021 19:55:08 +0100 Subject: [PATCH 08/15] Feature parity w/ Python #861 --- docs/core/tracer.md | 5 +- packages/tracing/README.md | 9 +- packages/tracing/src/Tracer.ts | 21 ++++- packages/tracing/src/middleware/middy.ts | 1 + packages/tracing/tests/unit/Tracer.test.ts | 96 +++++++++++++++++++-- packages/tracing/tests/unit/helpers.test.ts | 16 +--- packages/tracing/tests/unit/middy.test.ts | 44 ++++++++-- 7 files changed, 156 insertions(+), 36 deletions(-) diff --git a/docs/core/tracer.md b/docs/core/tracer.md index 2fb636b401..5b8197aa85 100644 --- a/docs/core/tracer.md +++ b/docs/core/tracer.md @@ -9,7 +9,7 @@ Tracer is an opinionated thin wrapper for [AWS X-Ray SDK for Node.js](https://gi ## Key features -* Auto capture cold start as annotation, and responses or full exceptions as metadata +* Auto capture cold start and service name as annotations, and responses or full exceptions as metadata * Auto-disable when not running in AWS Lambda environment * Support tracing functions via decorators, middleware, and manual instrumentation * Support tracing AWS SDK v2 and v3 via AWS X-Ray SDK for Node.js @@ -85,7 +85,8 @@ You can quickly start by importing the `Tracer` class, initialize it outside the const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) // Create subsegment for the function const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); - tracer.annotateColdStart() + tracer.annotateColdStart(); + tracer.addServiceNameAnnotation(); let res; try { diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 41cde322b4..48be2c1ae2 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -5,7 +5,7 @@ Tracer is an opinionated thin wrapper for [AWS X-Ray SDK for Node.js](https://gi Tracing data can be visualized through AWS X-Ray Console. ## Key features -* Auto capture cold start as annotation, and responses or full exceptions as metadata +* Auto capture cold start and service name as annotations, and responses or full exceptions as metadata * Auto-disable when not running in AWS Lambda environment * Support tracing functions via decorators, middleware, and manual instrumentation * Support tracing AWS SDK v2 and v3 via AWS X-Ray SDK for Node.js @@ -18,7 +18,7 @@ For more usage examples, see [our documentation](https://awslabs.github.io/aws-l If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: * handle the subsegment lifecycle -* add the `ColdStart` annotation +* add the `ServiceName` and `ColdStart` annotations * add the function response as metadata * add the function error as metadata (if any) @@ -37,7 +37,7 @@ export const handler = middy(async (_event: any, _context: any) => { If instead you use TypeScript Classes to wrap your Lambda handler you can use the [@tracer.captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html#captureLambdaHanlder) decorator to automatically: * handle the subsegment lifecycle -* add the `ColdStart` annotation +* add the `ServiceName` and `ColdStart` annotations * add the function response as metadata * add the function error as metadata (if any) @@ -70,7 +70,8 @@ export const handler = async (_event: any, context: any) => { const segment = tracer.getSegment(); // This is the facade segment (the one that is created by AWS Lambda) // Create subsegment for the function const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); - tracer.annotateColdStart() + tracer.annotateColdStart(); + tracer.addServiceNameAnnotation(); let res; try { diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 0e28180f9f..4579f54c2b 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -25,7 +25,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * * If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: * * handle the subsegment lifecycle - * * add the `ColdStart` annotation + * * add the `ServiceName` and `ColdStart` annotations * * add the function response as metadata * * add the function error as metadata (if any) * @@ -45,7 +45,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * * If instead you use TypeScript Classes to wrap your Lambda handler you can use the [@tracer.captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html#captureLambdaHanlder) decorator to automatically: * * handle the subsegment lifecycle - * * add the `ColdStart` annotation + * * add the `ServiceName` and `ColdStart` annotations * * add the function response as metadata * * add the function error as metadata (if any) * @@ -84,6 +84,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * // Create subsegment for the function * const handlerSegment = segment.addNewSubsegment(`## ${context.functionName}`); * tracer.annotateColdStart() + * tracer.addServiceNameAnnotation(); * * let res; * try { @@ -116,7 +117,7 @@ class Tracer implements TracerInterface { private envVarsService?: EnvironmentVariablesService; - private serviceName: string = 'serviceUndefined'; + private serviceName?: string; private tracingEnabled: boolean = true; @@ -148,7 +149,7 @@ class Tracer implements TracerInterface { } /** - * Add an data to the current segment or subsegment as metadata. + * Add response data to the current segment or subsegment as metadata. * * @see https://docs.aws.amazon.com/xray/latest/devguide/xray-concepts.html#xray-concepts-annotations * @@ -163,6 +164,17 @@ class Tracer implements TracerInterface { this.putMetadata(`${methodName} response`, data); } + /** + * Add service name to the current segment or subsegment as annotation. + * + */ + public addServiceNameAnnotation(): void { + if (this.tracingEnabled === false || this.serviceName === undefined) { + return; + } + this.putAnnotation('Service', this.serviceName); + } + /** * Add ColdStart annotation to the current segment or subsegment. * @@ -311,6 +323,7 @@ class Tracer implements TracerInterface { return this.provider.captureAsyncFunc(`## ${context.functionName}`, async subsegment => { this.annotateColdStart(); + this.addServiceNameAnnotation(); let result: unknown; try { result = await originalMethod?.apply(target, [ event, context, callback ]); diff --git a/packages/tracing/src/middleware/middy.ts b/packages/tracing/src/middleware/middy.ts index 58c9dd1d43..e0b984c825 100644 --- a/packages/tracing/src/middleware/middy.ts +++ b/packages/tracing/src/middleware/middy.ts @@ -32,6 +32,7 @@ const captureLambdaHandler = (target: Tracer): middy.MiddlewareObj => { const subsegment = new Subsegment(`## ${request.context.functionName}`); target.setSegment(subsegment); target.annotateColdStart(); + target.addServiceNameAnnotation(); } }; diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index 8894055f89..0138c562c9 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -65,6 +65,54 @@ describe('Class: Tracer', () => { }); + describe('Method: addServiceNameAnnotation', () => { + + test('when called while tracing is disabled, it does nothing', () => { + + // Prepare + const tracer: Tracer = new Tracer({ enabled: false }); + const putAnnotation = jest.spyOn(tracer, 'putAnnotation'); + + // Act + tracer.addServiceNameAnnotation(); + + // Assess + expect(putAnnotation).toBeCalledTimes(0); + + }); + + test('when called while a serviceName has been set, it adds it as annotation', () => { + + // Prepare + const tracer: Tracer = new Tracer({ serviceName: 'foo' }); + const putAnnotation = jest.spyOn(tracer, 'putAnnotation').mockImplementation(() => null); + + // Act + tracer.addServiceNameAnnotation(); + + // Assess + expect(putAnnotation).toBeCalledTimes(1); + expect(putAnnotation).toBeCalledWith('Service', 'foo'); + + }); + + test('when called while a serviceName has not been set, it does nothing', () => { + + // Prepare + delete process.env.POWERTOOLS_SERVICE_NAME; + const tracer: Tracer = new Tracer(); + const putAnnotation = jest.spyOn(tracer, 'putAnnotation').mockImplementation(() => null); + + // Act + tracer.addServiceNameAnnotation(); + + // Assess + expect(putAnnotation).toBeCalledTimes(0); + + }); + + }); + describe('Method: addResponseAsMetadata', () => { test('when called while tracing is disabled, it does nothing', () => { @@ -692,22 +740,60 @@ describe('Class: Tracer', () => { // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(2); expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); - expect(putAnnotationSpy).toHaveBeenCalledTimes(2); - expect(putAnnotationSpy.mock.calls).toEqual([ + expect(putAnnotationSpy.mock.calls.filter(call => + call[0] === 'ColdStart' + )).toEqual([ [ 'ColdStart', true ], [ 'ColdStart', false ], ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', - annotations: { + annotations: expect.objectContaining({ 'ColdStart': true, - } + }) })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', - annotations: { + annotations: expect.objectContaining({ 'ColdStart': false, + }) + })); + + }); + + test('when used as decorator and with standard config, it annotates Service correctly', async () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + jest.spyOn(tracer.provider, 'getSegment') + .mockImplementation(() => newSubsegment); + setContextMissingStrategy(() => null); + const captureAsyncFuncSpy = jest.spyOn(tracer.provider, 'captureAsyncFunc'); + class Lambda implements LambdaInterface { + + @tracer.captureLambdaHanlder() + // eslint-disable-next-line @typescript-eslint/ban-ts-comment + // @ts-ignore + public handler(_event: TEvent, _context: Context, _callback: Callback): void | Promise { + return new Promise((resolve, _reject) => resolve({ + foo: 'bar' + } as unknown as TResult)); } + + } + + // Act + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); + + // Assess + expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); + expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); + expect(newSubsegment).toEqual(expect.objectContaining({ + name: '## foo-bar-function', + annotations: expect.objectContaining({ + 'Service': 'hello-world', + }) })); }); diff --git a/packages/tracing/tests/unit/helpers.test.ts b/packages/tracing/tests/unit/helpers.test.ts index abc6a8c114..e64400d9dc 100644 --- a/packages/tracing/tests/unit/helpers.test.ts +++ b/packages/tracing/tests/unit/helpers.test.ts @@ -2,7 +2,7 @@ import { ConfigServiceInterface } from '../../src/config'; import { TracerOptions } from '../../src/types'; import { createTracer, Tracer } from './../../src'; -describe('Helper: createLogger function', () => { +describe('Helper: createTracer function', () => { const ENVIRONMENT_VARIABLES = process.env; beforeEach(() => { @@ -212,20 +212,6 @@ describe('Helper: createLogger function', () => { }); - test('when POWERTOOLS_SERVICE_NAME environment variable is set to invalid value, a tracer default serviceName is returned', () => { - // Prepare - process.env.POWERTOOLS_SERVICE_NAME = ''; - - // Act - const tracer = createTracer(); - - // Assess - expect(tracer).toEqual(expect.objectContaining({ - serviceName: 'serviceUndefined' - })); - - }); - test('when POWERTOOLS_TRACER_CAPTURE_RESPONSE environment variable is set, a tracer with captureResponse disabled is returned', () => { // Prepare process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = 'false'; diff --git a/packages/tracing/tests/unit/middy.test.ts b/packages/tracing/tests/unit/middy.test.ts index 944c3b354f..c45171f69d 100644 --- a/packages/tracing/tests/unit/middy.test.ts +++ b/packages/tracing/tests/unit/middy.test.ts @@ -232,22 +232,54 @@ describe('Middy middlewares', () => { expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ name: '## foo-bar-function', })); - expect(putAnnotationSpy).toHaveBeenCalledTimes(2); - expect(putAnnotationSpy.mock.calls).toEqual([ + expect(putAnnotationSpy.mock.calls.filter(call => + call[0] === 'ColdStart' + )).toEqual([ [ 'ColdStart', true ], [ 'ColdStart', false ], ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', - annotations: { + annotations: expect.objectContaining({ 'ColdStart': true, - } + }) })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ name: '## foo-bar-function', - annotations: { + annotations: expect.objectContaining({ 'ColdStart': false, - } + }) + })); + + }); + + test('when used with standard config, it annotates Service correctly', async () => { + + // Prepare + const tracer: Tracer = new Tracer(); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); + jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); + setContextMissingStrategy(() => null); + const lambdaHandler: Handler = async (_event: unknown, _context: Context) => ({ + foo: 'bar' + }); + const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); + const context = Object.assign({}, mockContext); + + // Act + await handler({}, context, () => console.log('Lambda invoked!')); + + // Assess + expect(setSegmentSpy).toHaveBeenCalledTimes(1); + expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ + name: '## foo-bar-function', + })); + expect(newSubsegment).toEqual(expect.objectContaining({ + name: '## foo-bar-function', + annotations: expect.objectContaining({ + 'Service': 'hello-world', + }) })); }); From c82d0feca6fdfbe6794d3438b769640b257463b1 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Mon, 20 Dec 2021 18:03:15 +0100 Subject: [PATCH 09/15] Revisited middleware implementation --- packages/tracing/src/Tracer.ts | 4 +- packages/tracing/src/middleware/middy.ts | 35 +++--- .../helpers/populateEnvironmentVariables.ts | 1 + packages/tracing/tests/unit/Tracer.test.ts | 34 +++--- packages/tracing/tests/unit/middy.test.ts | 105 ++++++++---------- 5 files changed, 86 insertions(+), 93 deletions(-) diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 4579f54c2b..05f4822e23 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -321,13 +321,13 @@ class Tracer implements TracerInterface { return originalMethod?.apply(target, [ event, context, callback ]); } - return this.provider.captureAsyncFunc(`## ${context.functionName}`, async subsegment => { + return this.provider.captureAsyncFunc(`## ${process.env._HANDLER}`, async subsegment => { this.annotateColdStart(); this.addServiceNameAnnotation(); let result: unknown; try { result = await originalMethod?.apply(target, [ event, context, callback ]); - this.addResponseAsMetadata(result, context.functionName); + this.addResponseAsMetadata(result, process.env._HANDLER); } catch (error) { this.addErrorAsMetadata(error as Error); throw error; diff --git a/packages/tracing/src/middleware/middy.ts b/packages/tracing/src/middleware/middy.ts index e0b984c825..2876b9f6de 100644 --- a/packages/tracing/src/middleware/middy.ts +++ b/packages/tracing/src/middleware/middy.ts @@ -1,6 +1,6 @@ import middy from '@middy/core'; -import { Subsegment } from 'aws-xray-sdk-core'; import { Tracer } from '../Tracer'; +import { Segment, Subsegment } from 'aws-xray-sdk-core'; /** * A middy middleware automating capture of metadata and annotations on segments or subsegments ofr a Lambda Handler. @@ -27,32 +27,41 @@ import { Tracer } from '../Tracer'; * @returns middleware object - The middy middleware object */ const captureLambdaHandler = (target: Tracer): middy.MiddlewareObj => { - const captureLambdaHandlerBefore = async (request: middy.Request): Promise => { + let lambdaSegment: Subsegment | Segment; + + const open = (): void => { + lambdaSegment = target.getSegment(); + const handlerSegment = lambdaSegment.addNewSubsegment(`## ${process.env._HANDLER}`); + target.setSegment(handlerSegment); + }; + + const close = (): void => { + const subsegment = target.getSegment(); + subsegment?.close(); + target.setSegment(lambdaSegment as Segment); + }; + + const captureLambdaHandlerBefore = async (_request: middy.Request): Promise => { if (target.isTracingEnabled()) { - const subsegment = new Subsegment(`## ${request.context.functionName}`); - target.setSegment(subsegment); + open(); target.annotateColdStart(); target.addServiceNameAnnotation(); } }; - + const captureLambdaHandlerAfter = async (request: middy.Request): Promise => { if (target.isTracingEnabled()) { - const subsegment = target.getSegment(); - target.addResponseAsMetadata(request.response, request.context.functionName); - subsegment.close(); + target.addResponseAsMetadata(request.response, process.env._HANDLER); + close(); } }; - + const captureLambdaHandlerError = async (request: middy.Request): Promise => { if (target.isTracingEnabled()) { - const subsegment = target.getSegment(); target.addErrorAsMetadata(request.error as Error); - // TODO: should this error be thrown?? I.e. should we stop the event flow & return? // throw request.error; - - subsegment?.close(); + close(); } }; diff --git a/packages/tracing/tests/helpers/populateEnvironmentVariables.ts b/packages/tracing/tests/helpers/populateEnvironmentVariables.ts index 61a62ffb9e..4721fef0d1 100644 --- a/packages/tracing/tests/helpers/populateEnvironmentVariables.ts +++ b/packages/tracing/tests/helpers/populateEnvironmentVariables.ts @@ -4,6 +4,7 @@ process.env.AWS_LAMBDA_FUNCTION_NAME = 'my-lambda-function'; process.env.AWS_EXECUTION_ENV = 'nodejs14.x'; process.env.AWS_LAMBDA_FUNCTION_MEMORY_SIZE = '128'; process.env.AWS_REGION = 'eu-central-1'; +process.env._HANDLER = 'index.handler'; // Powertools variables process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index 0138c562c9..a8631c594c 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -568,7 +568,7 @@ describe('Class: Tracer', () => { // Prepare process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = 'false'; const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); const captureAsyncFuncSpy = jest.spyOn(tracer.provider, 'captureAsyncFunc'); @@ -599,7 +599,7 @@ describe('Class: Tracer', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment') .mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -622,12 +622,12 @@ describe('Class: Tracer', () => { // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); - expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); + expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## index.handler', expect.anything()); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', metadata: { 'hello-world': { - 'foo-bar-function response': { + 'index.handler response': { foo: 'bar', }, }, @@ -641,7 +641,7 @@ describe('Class: Tracer', () => { // Prepare process.env.POWERTOOLS_TRACER_CAPTURE_ERROR = 'false'; const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment') .mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -663,7 +663,7 @@ describe('Class: Tracer', () => { await expect(new Lambda().handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', })); expect('cause' in newSubsegment).toBe(false); expect(addErrorFlagSpy).toHaveBeenCalledTimes(1); @@ -678,7 +678,7 @@ describe('Class: Tracer', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment') .mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -699,7 +699,7 @@ describe('Class: Tracer', () => { await expect(new Lambda().handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', })); expect('cause' in newSubsegment).toBe(true); expect(addErrorSpy).toHaveBeenCalledTimes(1); @@ -712,8 +712,8 @@ describe('Class: Tracer', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegmentFirstInvocation: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); - const newSubsegmentSecondInvocation: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegmentFirstInvocation: Segment | Subsegment | undefined = new Subsegment('## index.handler'); + const newSubsegmentSecondInvocation: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment') .mockImplementationOnce(() => newSubsegmentFirstInvocation) .mockImplementation(() => newSubsegmentSecondInvocation); @@ -739,7 +739,7 @@ describe('Class: Tracer', () => { // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(2); - expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); + expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## index.handler', expect.anything()); expect(putAnnotationSpy.mock.calls.filter(call => call[0] === 'ColdStart' )).toEqual([ @@ -747,13 +747,13 @@ describe('Class: Tracer', () => { [ 'ColdStart', false ], ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'ColdStart': true, }) })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'ColdStart': false, }) @@ -765,7 +765,7 @@ describe('Class: Tracer', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); jest.spyOn(tracer.provider, 'getSegment') .mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -788,9 +788,9 @@ describe('Class: Tracer', () => { // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(1); - expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## foo-bar-function', expect.anything()); + expect(captureAsyncFuncSpy).toHaveBeenCalledWith('## index.handler', expect.anything()); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'Service': 'hello-world', }) diff --git a/packages/tracing/tests/unit/middy.test.ts b/packages/tracing/tests/unit/middy.test.ts index c45171f69d..dc4069bf04 100644 --- a/packages/tracing/tests/unit/middy.test.ts +++ b/packages/tracing/tests/unit/middy.test.ts @@ -3,6 +3,7 @@ import middy from '@middy/core'; import { Tracer } from './../../src'; import type { Context, Handler } from 'aws-lambda/handler'; import { Segment, setContextMissingStrategy, Subsegment } from 'aws-xray-sdk-core'; +import { ContextExamples } from '@aws-lambda-powertools/commons'; jest.spyOn(console, 'debug').mockImplementation(() => null); jest.spyOn(console, 'warn').mockImplementation(() => null); @@ -11,21 +12,6 @@ jest.spyOn(console, 'error').mockImplementation(() => null); describe('Middy middlewares', () => { const ENVIRONMENT_VARIABLES = process.env; - const mockContext: Context = { - callbackWaitsForEmptyEventLoop: true, - functionVersion: '$LATEST', - functionName: 'foo-bar-function', - memoryLimitInMB: '128', - logGroupName: '/aws/lambda/foo-bar-function-123456abcdef', - logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456', - invokedFunctionArn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example', - awsRequestId: Math.floor(Math.random() * 1000000000).toString(), - getRemainingTimeInMillis: () => 1234, - done: () => console.log('Done!'), - fail: () => console.log('Failed!'), - succeed: () => console.log('Succeeded!'), - }; - beforeEach(() => { Tracer.coldStart = true; jest.clearAllMocks(); @@ -45,12 +31,12 @@ describe('Middy middlewares', () => { const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); const getSegmentSpy = jest.spyOn(tracer.provider, 'getSegment') .mockImplementationOnce(() => new Segment('facade', process.env._X_AMZN_TRACE_ID || null)) - .mockImplementationOnce(() => new Subsegment('## foo-bar-function')); + .mockImplementationOnce(() => new Subsegment('## index.handler')); const lambdaHandler: Handler = async (_event: unknown, _context: Context) => ({ foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); @@ -68,12 +54,12 @@ describe('Middy middlewares', () => { const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); const getSegmentSpy = jest.spyOn(tracer.provider, 'getSegment') .mockImplementationOnce(() => new Segment('facade', process.env._X_AMZN_TRACE_ID || null)) - .mockImplementationOnce(() => new Subsegment('## foo-bar-function')); + .mockImplementationOnce(() => new Subsegment('## index.handler')); const lambdaHandler: Handler = async (_event: unknown, _context: Context) => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); @@ -88,7 +74,7 @@ describe('Middy middlewares', () => { // Prepare process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE = 'false'; const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -96,13 +82,13 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); // Assess - expect(setSegmentSpy).toHaveBeenCalledTimes(1); + expect(setSegmentSpy).toHaveBeenCalledTimes(2); expect('metadata' in newSubsegment).toBe(false); delete process.env.POWERTOOLS_TRACER_CAPTURE_RESPONSE; @@ -112,7 +98,7 @@ describe('Middy middlewares', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -120,21 +106,18 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); // Assess - expect(setSegmentSpy).toHaveBeenCalledTimes(1); - expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ - name: '## foo-bar-function', - })); + expect(setSegmentSpy).toHaveBeenCalledTimes(2); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', metadata: { 'hello-world': { - 'foo-bar-function response': { + 'index.handler response': { foo: 'bar', }, }, @@ -148,7 +131,7 @@ describe('Middy middlewares', () => { // Prepare process.env.POWERTOOLS_TRACER_CAPTURE_ERROR = 'false'; const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -158,18 +141,15 @@ describe('Middy middlewares', () => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); - expect(setSegmentSpy).toHaveBeenCalledTimes(1); - expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ - name: '## foo-bar-function', - })); + expect(setSegmentSpy).toHaveBeenCalledTimes(2); expect('cause' in newSubsegment).toBe(false); expect(addErrorFlagSpy).toHaveBeenCalledTimes(1); expect(addErrorSpy).toHaveBeenCalledTimes(0); - expect.assertions(6); + expect.assertions(5); delete process.env.POWERTOOLS_TRACER_CAPTURE_ERROR; @@ -181,7 +161,7 @@ describe('Middy middlewares', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); @@ -190,18 +170,15 @@ describe('Middy middlewares', () => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); - expect(setSegmentSpy).toHaveBeenCalledTimes(1); - expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ - name: '## foo-bar-function', - })); + expect(setSegmentSpy).toHaveBeenCalledTimes(2); expect('cause' in newSubsegment).toBe(true); expect(addErrorSpy).toHaveBeenCalledTimes(1); expect(addErrorSpy).toHaveBeenCalledWith(new Error('Exception thrown!'), false); - expect.assertions(6); + expect.assertions(5); }); @@ -209,11 +186,14 @@ describe('Middy middlewares', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegmentFirstInvocation: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); - const newSubsegmentSecondInvocation: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const facadeSegment = new Segment('facade'); + const newSubsegmentFirstInvocation: Segment | Subsegment | undefined = new Subsegment('## index.handler'); + const newSubsegmentSecondInvocation: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); jest.spyOn(tracer.provider, 'getSegment') + .mockImplementationOnce(() => facadeSegment) .mockImplementationOnce(() => newSubsegmentFirstInvocation) + .mockImplementationOnce(() => facadeSegment) .mockImplementation(() => newSubsegmentSecondInvocation); setContextMissingStrategy(() => null); const putAnnotationSpy = jest.spyOn(tracer, 'putAnnotation'); @@ -221,17 +201,14 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); await handler({}, context, () => console.log('Lambda invoked!')); // Assess - expect(setSegmentSpy).toHaveBeenCalledTimes(2); - expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ - name: '## foo-bar-function', - })); + expect(setSegmentSpy).toHaveBeenCalledTimes(4); expect(putAnnotationSpy.mock.calls.filter(call => call[0] === 'ColdStart' )).toEqual([ @@ -239,13 +216,13 @@ describe('Middy middlewares', () => { [ 'ColdStart', false ], ]); expect(newSubsegmentFirstInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'ColdStart': true, }) })); expect(newSubsegmentSecondInvocation).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'ColdStart': false, }) @@ -257,26 +234,32 @@ describe('Middy middlewares', () => { // Prepare const tracer: Tracer = new Tracer(); - const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## foo-bar-function'); + const facadeSegment = new Segment('facade'); + const newSubsegment: Segment | Subsegment | undefined = new Subsegment('## index.handler'); const setSegmentSpy = jest.spyOn(tracer.provider, 'setSegment').mockImplementation(); - jest.spyOn(tracer.provider, 'getSegment').mockImplementation(() => newSubsegment); + jest.spyOn(tracer.provider, 'getSegment') + .mockImplementationOnce(() => facadeSegment) + .mockImplementation(() => newSubsegment); setContextMissingStrategy(() => null); const lambdaHandler: Handler = async (_event: unknown, _context: Context) => ({ foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, mockContext); + const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); // Assess - expect(setSegmentSpy).toHaveBeenCalledTimes(1); - expect(setSegmentSpy).toHaveBeenCalledWith(expect.objectContaining({ - name: '## foo-bar-function', - })); + expect(setSegmentSpy).toHaveBeenCalledTimes(2); + expect(setSegmentSpy.mock.calls.map(arg => ({ + name: arg[0].name, + }))).toEqual([ + expect.objectContaining({ name: '## index.handler' }), + expect.objectContaining({ name: 'facade' }), + ]); expect(newSubsegment).toEqual(expect.objectContaining({ - name: '## foo-bar-function', + name: '## index.handler', annotations: expect.objectContaining({ 'Service': 'hello-world', }) From be07b774cdce13aa9a1668991820e0da03e4eab8 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Tue, 21 Dec 2021 18:37:45 +0100 Subject: [PATCH 10/15] Fixed typo in jsdocs --- packages/tracing/src/Tracer.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 05f4822e23..0420149d2b 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -180,7 +180,7 @@ class Tracer implements TracerInterface { * * If Tracer has been initialized outside of the Lambda handler then the same instance * of Tracer will be reused throghout the lifecycle of that same Lambda execution environment - * and this method will return `false` after the first invocation. + * and this method will annotate `ColdStart: false` after the first invocation. * * @see https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html */ From 72332c0ebf09805a28c671a66a16ce10b5c08286 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Wed, 22 Dec 2021 10:59:15 +0100 Subject: [PATCH 11/15] Reverted to local context/event usage in tests --- packages/tracing/tests/unit/Tracer.test.ts | 24 ++++++++++++++++++---- packages/tracing/tests/unit/middy.test.ts | 23 +++++++++++++-------- 2 files changed, 34 insertions(+), 13 deletions(-) diff --git a/packages/tracing/tests/unit/Tracer.test.ts b/packages/tracing/tests/unit/Tracer.test.ts index a8631c594c..6b00a83761 100644 --- a/packages/tracing/tests/unit/Tracer.test.ts +++ b/packages/tracing/tests/unit/Tracer.test.ts @@ -1,5 +1,4 @@ import { LambdaInterface } from '../../examples/utils/lambda'; -import { Events, ContextExamples } from '@aws-lambda-powertools/commons'; import { Tracer } from '../../src'; import { Callback, Context } from 'aws-lambda/handler'; import { Segment, setContextMissingStrategy, Subsegment } from 'aws-xray-sdk-core'; @@ -10,8 +9,25 @@ jest.spyOn(console, 'error').mockImplementation(() => null); describe('Class: Tracer', () => { const ENVIRONMENT_VARIABLES = process.env; - const event = Events.Custom.CustomEvent; - const context = ContextExamples.helloworldContext; + const event = { + key1: 'value1', + key2: 'value2', + key3: 'value3', + }; + const context = { + callbackWaitsForEmptyEventLoop: true, + functionVersion: '$LATEST', + functionName: 'foo-bar-function', + memoryLimitInMB: '128', + logGroupName: '/aws/lambda/foo-bar-function-123456abcdef', + logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456', + invokedFunctionArn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example', + awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef', + getRemainingTimeInMillis: () => 1234, + done: () => console.log('Done!'), + fail: () => console.log('Failed!'), + succeed: () => console.log('Succeeded!'), + }; beforeEach(() => { Tracer.coldStart = true; @@ -556,7 +572,7 @@ describe('Class: Tracer', () => { } // Act - await new Lambda().handler(Events.Custom.CustomEvent, context, () => console.log('Lambda invoked!')); + await new Lambda().handler(event, context, () => console.log('Lambda invoked!')); // Assess expect(captureAsyncFuncSpy).toHaveBeenCalledTimes(0); diff --git a/packages/tracing/tests/unit/middy.test.ts b/packages/tracing/tests/unit/middy.test.ts index dc4069bf04..e1c6e0996c 100644 --- a/packages/tracing/tests/unit/middy.test.ts +++ b/packages/tracing/tests/unit/middy.test.ts @@ -3,7 +3,6 @@ import middy from '@middy/core'; import { Tracer } from './../../src'; import type { Context, Handler } from 'aws-lambda/handler'; import { Segment, setContextMissingStrategy, Subsegment } from 'aws-xray-sdk-core'; -import { ContextExamples } from '@aws-lambda-powertools/commons'; jest.spyOn(console, 'debug').mockImplementation(() => null); jest.spyOn(console, 'warn').mockImplementation(() => null); @@ -11,6 +10,20 @@ jest.spyOn(console, 'error').mockImplementation(() => null); describe('Middy middlewares', () => { const ENVIRONMENT_VARIABLES = process.env; + const context = { + callbackWaitsForEmptyEventLoop: true, + functionVersion: '$LATEST', + functionName: 'foo-bar-function', + memoryLimitInMB: '128', + logGroupName: '/aws/lambda/foo-bar-function-123456abcdef', + logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456', + invokedFunctionArn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example', + awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef', + getRemainingTimeInMillis: () => 1234, + done: () => console.log('Done!'), + fail: () => console.log('Failed!'), + succeed: () => console.log('Succeeded!'), + }; beforeEach(() => { Tracer.coldStart = true; @@ -36,7 +49,6 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); @@ -59,7 +71,6 @@ describe('Middy middlewares', () => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); @@ -82,7 +93,6 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); @@ -106,7 +116,6 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); @@ -141,7 +150,6 @@ describe('Middy middlewares', () => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); @@ -170,7 +178,6 @@ describe('Middy middlewares', () => { throw new Error('Exception thrown!'); }; const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act & Assess await expect(handler({}, context, () => console.log('Lambda invoked!'))).rejects.toThrowError(Error); @@ -201,7 +208,6 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); @@ -245,7 +251,6 @@ describe('Middy middlewares', () => { foo: 'bar' }); const handler = middy(lambdaHandler).use(captureLambdaHandler(tracer)); - const context = Object.assign({}, ContextExamples.helloworldContext); // Act await handler({}, context, () => console.log('Lambda invoked!')); From 23e5a36c7d77f8da86dbc5a0d9c479566ff52b0c Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 23 Dec 2021 10:01:07 +0100 Subject: [PATCH 12/15] Update packages/tracing/src/Tracer.ts Co-authored-by: Sara Gerion <47529391+saragerion@users.noreply.github.com> --- packages/tracing/src/Tracer.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/src/Tracer.ts b/packages/tracing/src/Tracer.ts index 0420149d2b..e0eee4f31f 100644 --- a/packages/tracing/src/Tracer.ts +++ b/packages/tracing/src/Tracer.ts @@ -23,7 +23,7 @@ import { Segment, Subsegment } from 'aws-xray-sdk-core'; * * ### Functions usage with middlewares * - * If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: + * If you use function-based Lambda handlers you can use the [captureLambdaHandler()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: * * handle the subsegment lifecycle * * add the `ServiceName` and `ColdStart` annotations * * add the function response as metadata From 744f3d925317d0ec007c7b9a97db286287c0d77c Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 23 Dec 2021 10:01:21 +0100 Subject: [PATCH 13/15] Update packages/tracing/README.md Co-authored-by: Sara Gerion <47529391+saragerion@users.noreply.github.com> --- packages/tracing/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 48be2c1ae2..2616f3ac5d 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -47,7 +47,7 @@ import { Tracer } from '@aws-lambda-powertools/tracer'; const tracer = new Tracer({ serviceName: 'my-service' }); class Lambda { - @tracer.captureLambdaHanlder() + @tracer.captureLambdaHandler() public handler(event: any, context: any) { ... } From 4c22813a17c42b05295f94eac14bf8ee59b40058 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 23 Dec 2021 10:01:30 +0100 Subject: [PATCH 14/15] Update packages/tracing/README.md Co-authored-by: Sara Gerion <47529391+saragerion@users.noreply.github.com> --- packages/tracing/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 2616f3ac5d..6bb8a28507 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -35,7 +35,7 @@ export const handler = middy(async (_event: any, _context: any) => { ### Object oriented usage with decorators -If instead you use TypeScript Classes to wrap your Lambda handler you can use the [@tracer.captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html#captureLambdaHanlder) decorator to automatically: +If instead you use TypeScript Classes to wrap your Lambda handler you can use the [@tracer.captureLambdaHandler()](./_aws_lambda_powertools_tracer.Tracer.html#captureLambdaHandler) decorator to automatically: * handle the subsegment lifecycle * add the `ServiceName` and `ColdStart` annotations * add the function response as metadata From 8cedc4b01417890d88caa7cfa4830c3622f73b94 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 23 Dec 2021 10:01:36 +0100 Subject: [PATCH 15/15] Update packages/tracing/README.md Co-authored-by: Sara Gerion <47529391+saragerion@users.noreply.github.com> --- packages/tracing/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/README.md b/packages/tracing/README.md index 6bb8a28507..d73d2455bb 100644 --- a/packages/tracing/README.md +++ b/packages/tracing/README.md @@ -16,7 +16,7 @@ For more usage examples, see [our documentation](https://awslabs.github.io/aws-l ### Functions usage with middlewares -If you use function-based Lambda handlers you can use the [captureLambdaHanlder()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: +If you use function-based Lambda handlers you can use the [captureLambdaHandler()](./_aws_lambda_powertools_tracer.Tracer.html) middy middleware to automatically: * handle the subsegment lifecycle * add the `ServiceName` and `ColdStart` annotations * add the function response as metadata