powertools-lambda-typescript: Bug: Tracer: Time gap between LambdaInvoke and Handler

Expected Behaviour

On XRay console, Trace details, I expected to see no time gap between Lambda Invoke and Lambda handler.

Current Behaviour

When I see the results of a trace I can see a gap between the start of Lambda invoke and handler. The reason for this gap is unknown.

Note1: I am using Provisioned concurrency Note2: I’ve opened an AWS ticket to get an explanation for this behavior and they say this might be specific to my code, which uses Powertools to handle tracing Note3: This gap is bigger on the first call. However, there is no static code or getParameter in this test. However, I do get a connection from a database and keep the connection for subsequent calls. The method that gets the connection is instrumented manually. Example gap scenario on first call:

Invocation: 417ms Handler: 279ms gap: 138ms

The gap happens mostly before the handler: before handler: 126ms

Code snippet

Handler instrumentation

// Decorate your handler class method
  @logger.injectLambdaContext()
  @tracer.captureLambdaHandler()
  public async handler(
    event: APIGatewayProxyEvent,
    context: Context,
  ): Promise<APIGatewayProxyResult> {
    const start = performance.now();
    console.log('Function hanlder starting...');

    const response = await super.handler(event, context);
    // Measure
    const end = performance.now();
    console.log(`Function handler executed in ${end - start}ms`);
    return response;
  }

GetConnection instrumentation (if there is a less verbose method that does not use decorators I would be glad to hear)

// get a database connection
  protected async getDbConnection(
    dbOptions: mysql.ConnectionOptions
  ): Promise<mysql.Connection> {
    // Open new subSegment
    const parentSubsegment = this.tracer?.getSegment(); // This is the subsegment currently active
    let subsegment;
    if (parentSubsegment) {
      // Create subsegment for the function & set it as active
      subsegment = parentSubsegment.addNewSubsegment(`### getDbConnection`);
      this.tracer?.setSegment(subsegment);
    }

    const dbConnection = await mysql.createConnection(dbOptions);

    // Close subSegment
    if (parentSubsegment && subsegment) {
      // Close subsegment (the AWS Lambda one is closed automatically)
      subsegment.close();
      // Set the facade segment as active again
      this.tracer?.setSegment(parentSubsegment);
    }

    return dbConnection;
  }

Steps to Reproduce

  1. Provisioned concurrent lambda
  2. No VPC
  3. No static Code
  4. No getParameter used
  5. Tracer configured with decorator on handler method

Possible Solution

No suggestion for now

Powertools for AWS Lambda (TypeScript) version

1.12.1

AWS Lambda function runtime

16.x

Packaging format used

npm

Execution logs

INIT_START Runtime Version: nodejs:16.v20	Runtime Version ARN: arn:aws:lambda:sa-east-1::runtime:221c9e1eaf373c676cf0d1bff6642d8cb3ba2642dbad7a8c56624b0fddc4ffcd
2023-10-12T14:37:10.700Z	undefined	INFO	Before any import
2023-10-12T14:37:10.701Z	undefined	INFO	Start global context
2023-10-12T14:37:10.701Z	undefined	INFO	Before export handler
2023-10-12T14:37:10.701Z	undefined	INFO	constructor executed in 0.049075999995693564ms
2023-10-12T14:37:10.701Z	undefined	INFO	Global context executed in 0.5833669999992708ms
START RequestId: aba2e6cf-982e-4eb9-8249-1d7b11471e67 Version: 21
{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Lambda invocation event",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:44:59.783Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "event": {
        "resource": "/",
        "path": "/",
        "httpMethod": "POST",
        "headers": {
            "Accept": "*/*",
            "Content-Type": "text/xml",
            "Host": "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com",
            "User-Agent": "curl/8.0.1",
            "x-amzn-cipher-suite": "ECDHE-RSA-AES128-GCM-SHA256",
            "x-amzn-tls-version": "TLSv1.2",
            "x-amzn-vpc-id": "vpc-055f0d77c5aa8d6f9",
            "x-amzn-vpce-config": "1",
            "x-amzn-vpce-id": "vpce-0fd8d0b1be931eab1",
            "X-Forwarded-For": "10.0.0.51"
        },
        "multiValueHeaders": {
            "Accept": [
                "*/*"
            ],
            "Content-Type": [
                "text/xml"
            ],
            "Host": [
                "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com"
            ],
            "User-Agent": [
                "curl/8.0.1"
            ],
            "x-amzn-cipher-suite": [
                "ECDHE-RSA-AES128-GCM-SHA256"
            ],
            "x-amzn-tls-version": [
                "TLSv1.2"
            ],
            "x-amzn-vpc-id": [
                "vpc-055f0d77c5aa8d6f9"
            ],
            "x-amzn-vpce-config": [
                "1"
            ],
            "x-amzn-vpce-id": [
                "vpce-0fd8d0b1be931eab1"
            ],
            "X-Forwarded-For": [
                "10.0.0.51"
            ]
        },
        "queryStringParameters": null,
        "multiValueQueryStringParameters": null,
        "pathParameters": null,
        "stageVariables": null,
        "requestContext": {
            "resourceId": "v46zht1add",
            "resourcePath": "/",
            "httpMethod": "POST",
            "extendedRequestId": "MsXw3FvlGjQFVWw=",
            "requestTime": "12/Oct/2023:14:44:59 +0000",
            "path": "/prod/",
            "accountId": "272998361838",
            "protocol": "HTTP/1.1",
            "stage": "prod",
            "domainPrefix": "shrpn1l6q8",
            "requestTimeEpoch": 1697121899645,
            "requestId": "6becfce3-9b53-4bbe-be99-00db25347473",
            "identity": {
                "cognitoIdentityPoolId": null,
                "cognitoIdentityId": null,
                "vpceId": "vpce-0fd8d0b1be931eab1",
                "principalOrgId": null,
                "cognitoAuthenticationType": null,
                "userArn": null,
                "userAgent": "curl/8.0.1",
                "accountId": null,
                "caller": null,
                "sourceIp": "10.0.0.51",
                "accessKey": null,
                "vpcId": "vpc-055f0d77c5aa8d6f9",
                "cognitoAuthenticationProvider": null,
                "user": null
            },
            "domainName": "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com",
            "apiId": "shrpn1l6q8"
        },
        "body": "<soap:Envelope xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\">    <SOAP-ENV:Header xmlns:SOAP-ENV=\"http://schemas.xmlsoap.org/soap/envelope/\"/>        <soap:Body>            <MaintenanceRequest xmlns=\"http://www.comviva.com/asa/maintenancewindow/result\">                <area_cn>21</area_cn>                <origin>API</origin>                <module_name>orchestrator</module_name>            </MaintenanceRequest>        </soap:Body></soap:Envelope>",
        "isBase64Encoded": false
    }
}

2023-10-12T14:44:59.823Z	aba2e6cf-982e-4eb9-8249-1d7b11471e67	INFO	Function hanlder starting...
{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "DEBUG",
    "message": "Getting new DB connection...",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:44:59.824Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1"
}

{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "DEBUG",
    "message": "Fetching DB options...",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:44:59.841Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1"
}

{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "DEBUG",
    "message": "Got new DB connection.",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:44:59.961Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1"
}

{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Initializing controller...",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:44:59.962Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1"
}

2023-10-12T14:44:59.963Z	aba2e6cf-982e-4eb9-8249-1d7b11471e67	INFO	initialize method executed in 138.73253599996679ms
2023-10-12T14:44:59.981Z	aba2e6cf-982e-4eb9-8249-1d7b11471e67	INFO	processRequest called
{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Validate payload document",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:00.005Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1"
}

{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Execute domain service",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:00.007Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Trying to get maintenance window info by area and module...",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:00.007Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

2023-10-12T14:45:00.085Z	aba2e6cf-982e-4eb9-8249-1d7b11471e67	INFO	Function handler executed in 261.5502710000146ms
{
    "cold_start": true,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "aba2e6cf-982e-4eb9-8249-1d7b11471e67",
    "level": "INFO",
    "message": "Build response payload",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:00.084Z",
    "xray_trace_id": "1-6528066b-c2469549fd6df1f6f4d81d47",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

END RequestId: aba2e6cf-982e-4eb9-8249-1d7b11471e67
REPORT RequestId: aba2e6cf-982e-4eb9-8249-1d7b11471e67	Duration: 457.99 ms	Billed Duration: 458 ms	Memory Size: 256 MB	Max Memory Used: 131 MB	Init Duration: 5450.35 ms	
XRAY TraceId: 1-6528066b-c2469549fd6df1f6f4d81d47	SegmentId: 47d8cf8b3c87a056	Sampled: true	
START RequestId: afe0085d-6a27-47fb-9120-7d01597c8f98 Version: 21
{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "INFO",
    "message": "Lambda invocation event",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.036Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API",
    "event": {
        "resource": "/",
        "path": "/",
        "httpMethod": "POST",
        "headers": {
            "Accept": "*/*",
            "Content-Type": "text/xml",
            "Host": "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com",
            "User-Agent": "curl/8.0.1",
            "x-amzn-cipher-suite": "ECDHE-RSA-AES128-GCM-SHA256",
            "x-amzn-tls-version": "TLSv1.2",
            "x-amzn-vpc-id": "vpc-055f0d77c5aa8d6f9",
            "x-amzn-vpce-config": "1",
            "x-amzn-vpce-id": "vpce-0fd8d0b1be931eab1",
            "X-Forwarded-For": "10.0.0.51"
        },
        "multiValueHeaders": {
            "Accept": [
                "*/*"
            ],
            "Content-Type": [
                "text/xml"
            ],
            "Host": [
                "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com"
            ],
            "User-Agent": [
                "curl/8.0.1"
            ],
            "x-amzn-cipher-suite": [
                "ECDHE-RSA-AES128-GCM-SHA256"
            ],
            "x-amzn-tls-version": [
                "TLSv1.2"
            ],
            "x-amzn-vpc-id": [
                "vpc-055f0d77c5aa8d6f9"
            ],
            "x-amzn-vpce-config": [
                "1"
            ],
            "x-amzn-vpce-id": [
                "vpce-0fd8d0b1be931eab1"
            ],
            "X-Forwarded-For": [
                "10.0.0.51"
            ]
        },
        "queryStringParameters": null,
        "multiValueQueryStringParameters": null,
        "pathParameters": null,
        "stageVariables": null,
        "requestContext": {
            "resourceId": "v46zht1add",
            "resourcePath": "/",
            "httpMethod": "POST",
            "extendedRequestId": "MsXx3E0_mjQFlVA=",
            "requestTime": "12/Oct/2023:14:45:06 +0000",
            "path": "/prod/",
            "accountId": "272998361838",
            "protocol": "HTTP/1.1",
            "stage": "prod",
            "domainPrefix": "shrpn1l6q8",
            "requestTimeEpoch": 1697121906016,
            "requestId": "55830c8e-7045-47fe-8610-1f0ce9365282",
            "identity": {
                "cognitoIdentityPoolId": null,
                "cognitoIdentityId": null,
                "vpceId": "vpce-0fd8d0b1be931eab1",
                "principalOrgId": null,
                "cognitoAuthenticationType": null,
                "userArn": null,
                "userAgent": "curl/8.0.1",
                "accountId": null,
                "caller": null,
                "sourceIp": "10.0.0.51",
                "accessKey": null,
                "vpcId": "vpc-055f0d77c5aa8d6f9",
                "cognitoAuthenticationProvider": null,
                "user": null
            },
            "domainName": "shrpn1l6q8.execute-api.sa-east-1.amazonaws.com",
            "apiId": "shrpn1l6q8"
        },
        "body": "<soap:Envelope xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\">    <SOAP-ENV:Header xmlns:SOAP-ENV=\"http://schemas.xmlsoap.org/soap/envelope/\"/>        <soap:Body>            <MaintenanceRequest xmlns=\"http://www.comviva.com/asa/maintenancewindow/result\">                <area_cn>21</area_cn>                <origin>API</origin>                <module_name>orchestrator</module_name>            </MaintenanceRequest>        </soap:Body></soap:Envelope>",
        "isBase64Encoded": false
    }
}

2023-10-12T14:45:06.038Z	afe0085d-6a27-47fb-9120-7d01597c8f98	INFO	processRequest called
2023-10-12T14:45:06.038Z	afe0085d-6a27-47fb-9120-7d01597c8f98	INFO	initialize method executed in 0.38570700003765523ms
2023-10-12T14:45:06.038Z	afe0085d-6a27-47fb-9120-7d01597c8f98	INFO	Function hanlder starting...
{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "DEBUG",
    "message": "Reusing database connection.",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.038Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "INFO",
    "message": "Validate payload document",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.039Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "INFO",
    "message": "Execute domain service",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.040Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "INFO",
    "message": "Trying to get maintenance window info by area and module...",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.041Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

2023-10-12T14:45:06.044Z	afe0085d-6a27-47fb-9120-7d01597c8f98	INFO	Function handler executed in 6.712112999986857ms
{
    "cold_start": false,
    "function_arn": "arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias",
    "function_memory_size": 256,
    "function_name": "MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh",
    "function_request_id": "afe0085d-6a27-47fb-9120-7d01597c8f98",
    "level": "INFO",
    "message": "Build response payload",
    "service": "MaintenanceWindow",
    "timestamp": "2023-10-12T14:45:06.044Z",
    "xray_trace_id": "1-65280672-554763a5a39a257496cc43be",
    "aws_account_id": "N/A",
    "aws_region": "sa-east-1",
    "module": "orchestrator",
    "area": "21",
    "origin": "API"
}

END RequestId: afe0085d-6a27-47fb-9120-7d01597c8f98
REPORT RequestId: afe0085d-6a27-47fb-9120-7d01597c8f98	Duration: 25.72 ms	Billed Duration: 26 ms	Memory Size: 256 MB	Max Memory Used: 132 MB	
XRAY TraceId: 1-65280672-554763a5a39a257496cc43be	SegmentId: 04ad00e704b0d140	Sampled: true

About this issue

  • Original URL
  • State: closed
  • Created 9 months ago
  • Comments: 17 (10 by maintainers)

Most upvoted comments

Oi @leandrodamascena , obrigado pela ajuda! Vejo que vc é um pai babão… 😉

sim, muito! hahaha ❤️

Going back to the case, here is the info you’ve requested.

Thank you very much for sending all this information. I will put it in the ticket and follow up on the response from the service team. We can’t say how long it will take to update this issue as it will take some time to review, but we will monitor the ticket and report back here as soon as we have any updates.

Thank you very much for your patience and information.

+1
leandrodamascena on Oct 17, 2023

Oi @leandrodamascena , obrigado pela ajuda! Vejo que vc é um pai babão… 😉 Going back to the case, here is the info you’ve requested.

First call (“cold start”) arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias reqId: aba2e6cf-982e-4eb9-8249-1d7b11471e67 mem:256 trace: 1-6528066b-c2469549fd6df1f6f4d81d47 gap:197ms cold_start: true

Second, subsequent call (not cold start) arn:aws:lambda:sa-east-1:272998361838:function:MaintenanceWindow-IntegrationLambdaFunction434D807-kfqZPYkps7fh:provisioned-lambda-alias reqId: afe0085d-6a27-47fb-9120-7d01597c8f98 mem:256 trace: 1-65280672-554763a5a39a257496cc43be gap: 19ms cold_start: false,

Besides the X-Ray trace prints, I’ve attached Cloud Watch logs generated by powertools since they are full of info.

trace_1-6528066b-c2469549fd6df1f6f4d81d47 trace_1-65280672-554763a5a39a257496cc43be

log_lambda_12_10.txt

+1
marcioemiranda on Oct 17, 2023

Hi @marcioemiranda, thank you for sharing your latest findings - appreciate you letting us know.

We have been working on this and @leandrodamascena was able to reproduce the behavior you described. We still need to properly understand why this is happening, so in order to do this we are going to open an internal ticket to get a better idea of why we are seeing this gap.

Once we hear back from them we will share as much information as we can.

Thank you for your patience.

+1
dreamorosi on Oct 16, 2023
Read more comments on GitHub
← powertools-lambda-python: SAM CLI Bug: APIGatewayRestResolver and APIGatewayHttpResolver behave differently in local environment
powertools-lambda-typescript: Bug: unable to build with `tsc` when not using `@middy/core` →