aws-powertools / powertools-lambda-typescript

Powertools is a developer toolkit to implement Serverless best practices and increase developer velocity.
https://docs.powertools.aws.dev/lambda/typescript/latest/
MIT No Attribution
1.5k stars 130 forks source link

Feature request: avoid tracing API calls made during init (top-level `await`) #2406

Open dreamorosi opened 2 months ago

dreamorosi commented 2 months ago

Use case

Currently when using the Parameters and Tracer utility together, and with top-level await (like shown below) used in a certain order an error is logged (but not thrown) informing that the X-Ray SDK is unable to find a trace root (expected).

import { Tracer } from '@aws-lambda-powertools/tracer';
import { Logger } from '@aws-lambda-powertools/logger';
import { getParameter } from '@aws-lambda-powertools/parameters/ssm';

/**
 * note that tracer is instantiated before the `getParameter` call
 * from this point on, http calls (including the ones with AWS SDK) are traced
 */
const tracer = new Tracer();
const logger = new Logger();
const ssmParameter = await getParameter('/layers/powertools-layer-arn');

export const handler = async () => {
  logger.info('param', { ssmParameter });

  return {
    statusCode: 200,
    body: JSON.stringify("Hello, World!"),
  };
};

This is the log emitted by the AWS X-Ray SDK, which attempts to trace the request made

2024-04-19T21:34:27.204Z        undefined       ERROR   Error: Missing AWS Lambda trace data for X-Ray. Ensure Active Tracing is enabled and no subsegments are created outside the function handler.
    at Object.contextMissing (file:///var/task/index.mjs:7:16736)
    at e.resolveLambdaTraceData (file:///var/task/index.mjs:7:36770)
    at Object.getSegment (file:///var/task/index.mjs:7:17544)
    at Object.resolveSegment (file:///var/task/index.mjs:7:17251)
    at n (file:///var/task/index.mjs:7:95499)
    at s (file:///var/task/index.mjs:7:97066)
    at /var/runtime/node_modules/@aws-sdk/node_modules/@smithy/node-http-handler/dist-cjs/index.js:233:19
    at new Promise (<anonymous>)
    at _NodeHttpHandler.handle (/var/runtime/node_modules/@aws-sdk/node_modules/@smithy/node-http-handler/dist-cjs/index.js:189:12)
    at async /var/runtime/node_modules/@aws-sdk/node_modules/@smithy/middleware-serde/dist-cjs/index.js:33:24
START RequestId: 1ae7c9e3-37d1-4110-b8c0-cdb63b70b69d Version: $LATEST
{"level":"INFO","message":"param","sampling_rate":0,"service":"service_undefined","timestamp":"2024-04-19T21:34:27.305Z","xray_trace_id":"1-6622e362-563b8ad23b746432303d77c6","ssmParameter":"arn:aws:lambda:eu-west-1:123456789101:layer:AWSLambdaPowertoolsTypeScriptV2:5"}
END RequestId: 1ae7c9e3-37d1-4110-b8c0-cdb63b70b69d
REPORT RequestId: 1ae7c9e3-37d1-4110-b8c0-cdb63b70b69d  Duration: 50.72 ms      Billed Duration: 51 ms  Memory Size: 128 MB     Max Memory Used: 94 MB  Init Duration: 553.91 ms
XRAY TraceId: 1-6622e362-563b8ad23b746432303d77c6       SegmentId: 1e9f991047253160     Sampled: true

This is expected in the sense that trace data is available only within the handler scope and made available by the AWS Lambda service only when invoking your function.

This is not a runtime error (which is also why this is a feature request and not a bug) but nevertheless it's a nuisance and we should try to find a way to handle this case without making the AWS X-Ray SDK log the error.

Note that swapping the order of the Tracer instantiation and the Parameters call, like below, fixes the issue:

const ssmParameter = await getParameter('/layers/powertools-layer-arn');
// this is fine because http tracing starts after this point and the call already happened
const tracer = new Tracer();

Solution/User Experience

The experience for customers should stay as-is and the change should be backwards compatible.

Alternative solutions

No response

Acknowledgment

Future readers

Please react with 👍 and your use case to help us understand customer demand.

aripalo commented 2 months ago

Just landed here as I was wondering why I'm seeing that error.

My use case isn't necessary valid. I was just testing out various (premature 😅 ) optimizations where I call one async function (that essentially initializes a Promise that starts making HTTP calls) before the handler function and then later in the handler I actually await the value of that Promise. I'm not yet even sure if I that makes any real difference, but generally speaking I can see think of various reasons of doing similar things.

HaaLeo commented 5 days ago

Is there maybe a workaround to disable the logging of that error? This error message clutters our logs 😅.

dreamorosi commented 5 days ago

The log comes from the X-Ray SDK for Node.js as we can see from the stack trace above.

I haven't tested it, but I think setting the AWS_XRAY_CONTEXT_MISSING env var to IGNORE_ERROR as specified here might do the trick.

HaaLeo commented 5 days ago

Thx for the answer, I'll try that.

HaaLeo commented 5 days ago

I can confirm that with the environment variable AWS_XRAY_CONTEXT_MISSING set to IGNORE_ERROR the error is no longer logged 👍🏼. Thank you for the hint @dreamorosi.