aws / aws-xray-sdk-node

The official AWS X-Ray SDK for Node.js.
Apache License 2.0
273 stars 156 forks source link

Annotation not set for Lambda (not using Express) #222

Open chearmstrong opened 5 years ago

chearmstrong commented 5 years ago

Hi.

In my lambda handler, I'm trying to set an annotation on a subsegment. I'm not using express.

const sub = AWSXRay.getSegment().addNewSubsegment('my-handler')

// Rest of my code...

sub.addAnnotation('response', JSON.stringify(response))

I can't see this set anywhere though. What am I missing?

Thanks in advance.

willarmiros commented 5 years ago

Hi @chearmstrong, There are (at least) two possibilities here. The first is you are not closing your subsegment with sub.close(error) - which you must to guarantee all its attributes are included. The other is that this is a similar issue to #219 in which there are asynchronous functions in your code which cause the segment for the function to be ended prematurely, before your addAnnotation is reached. Please provide some more repro code to help determine which root cause is more likely.

chearmstrong commented 5 years ago

Thanks for the reply @willarmiros - here's more code. I suspect it's the async thing. Is there a workaround for this atm?

I changed it to use captureAsyncFunc which is better - on some requests I see everything. However, not on others. Interestingly, it's a request where I also call SQS which seems to be missing stuff.

const handler = async event => {
  return AWSXRay.captureAsyncFunc('my-handler', subSegment => {
    subSegment.addAnnotation('body', JSON.stringify(event.body))

    return handleEvent(event)
      .then(response => {
        subSegment.addAnnotation('response', JSON.stringify(response))
        subSegment.close()

        return getSuccessResponse(response)
      })
      .catch(error => {
        subSegment.close(error, false)

        return getErrorResponse(error)
      })
  })
}
willarmiros commented 4 years ago

Hi @chearmstrong, What's interesting is that I could not reproduce your issue with some generic handleEvent async function. Maybe it's because mine was a little too fast, but not sure exactly.

What happens in general in these types of situations is execution hits an async function like handleEvent and that function executes and returns quickly, as it should, because its callback (.then in this case) will eventually be added to the task queue to be executed later. However because handleEvent has finished executing, the top-level handler has reached the end of its execution and can now return its promise. The Lambda function correctly waits for this promise to be resolved before terminating, however I believe the X-Ray segment is sent before the promise is resolved, meaning the actions like adding that annotation are not reflected in the prematurely sent segment.

I hope this makes some sense. We are investigating this issue with Lambda currently. I will update this thread as we learn more.

willarmiros commented 4 years ago

Hi @chearmstrong, Are you still experiencing this error? Here's the code I'm using to reproduce on Lambda, with node 12.x and X-Ray SDK 3.0.0:

const AWSXRay = require('aws-xray-sdk');

exports.handler = async event => {
  return AWSXRay.captureAsyncFunc('my-handler', subSegment => {
    subSegment.addAnnotation('body', JSON.stringify(event));

    return handleEvent(event)
      .then(response => {
        console.log('response=' + response);
        subSegment.addAnnotation('response', response);
        subSegment.close();

        return response;
      })
      .catch(error => {
        subSegment.close(error, false);

        return error;
      });
  });
};

async function handleEvent(event) {
  let promise = new Promise((resolve, reject) => {
    setTimeout(() => resolve("done!"), 1000);
  });

  let result = await promise;
  return result;
}

Perhaps the use of cls-hooked in 3.0.0 helped? I've consistently seen the correct annotation added when trying to reproduce the error, so please let me know if you can get the error reproduced more consistently.

chearmstrong commented 4 years ago

Just been checking this one with v3 seems to be working as expected now (on our staging env at least). Will update prod with sees a lot of requests and monitor it - will come back if have an more issues.

benheymink commented 1 year ago

@willarmiros I think I'm seeing this too (not using express, but rather, using lambda-api to handle request routing. I'm just trying to add a top level annotation as follows, but nothing is being recorded:

import AWSXRay from 'aws-xray-sdk';

// lambda-api route handler
api.get('/some_route', async () => {
    const segment = AWSXRay.getSegment();
    segment.addAnnotation('myAnnotation', 'some_value');

    return someAsyncFunctionCallThatHitsOurDB();
});
benheymink commented 1 year ago

Ah, is this the whole 'top level segment in lambda is immutable' issue? If so, would be nice if there was an easy way to generate a custom subsegment for the lambda too. (In this case I might be able to do it with lambda-api middleware...