Unable to add annotations within a lambda handler

[nbeyer]

Given a very simple Lambda handler function like this:

func Handler(ctx context.Context, request events.APIGatewayProxyRequest) (events.APIGatewayProxyResponse, error) {
	if err := xray.AddAnnotation(ctx, "PLEASE_WORK", "NOPE"); err != nil {
	        log.Printf("Error returned adding annotation: %v", err)
         }
        // do some work
}

This produces a 'unable to retrieve segment' error every time. I was under the impression that there was an implied segment started for the handler, but that doesn't seem to be the case. Am I supposed to BeginSubsegment at the start of the handler method?

[haotianw465]

You are right. The segment wrapping the entire function execution is generated by the Lambda container and it is sent separately with tracing data generated by the SDK. The SDK doesn't have access to the Lambda segment today so you will need to wrap your function code using BeginSubsegment if you want to add extra information within your function.

We are working with Lambda team to make the integration seamless. Please stay tuned. Feel free to put any additional concerns here.

[nbeyer]

Adding a BeginSubsegment seems to make things worse. All of the subsegments that were being produced via the other AWS clients and HTTP clients are now gone. Oddly, I have the xray sdk's logging on trace and i see my wrapper segment being started and emitted, but when i take the trace id associated with it and look it up in the console, the only segments are the two lambda segments with the origin AWS::Lambda and AWS::Lambda::Function.

[haotianw465]

Hi,

Could you provide a code snippet of how you wrap your function within a subsegment so we can take a further look? Do you have any example log entry and the raw trace data?

Make sure you wrap the function using recommended syntax at https://github.com/aws/aws-xray-sdk-go under Start a custom segment/subsegment or Capture section and make sure you provide a valid subsegment name.

The simplest way in your case might be a sentinel subsegment as for the actual function code you might only care about the real AWS calls and HTTP calls and don't want an extra layer around the entire function. It could look like:

  ctx, subSeg := xray.BeginSubsegment(ctx, "sentinel")
  xray.AddAnnotation(ctx, "PLEASE_WORK", "NOPE");
  subSeg.Close(nil)

Since X-Ray service aggregates annotations/metadata on trace level for trace filtering so you can get the trace back by calling GetTraceSummaries with filter expression annotation.PLEASE_WORK = "NOPE" regardless of which subsegment this annotation gets added to. But you will still see a difference on the raw trace json retrieved by BatchGetTraces API.

Please let me know if this would work better for your use case.

[nbeyer]

Adding a sentinel isn't really what I want to do and I'd like to be able to add custom subsegments for other functional groupings in the code and that doesn't seem to be working. I'll work up some trimmed down code snippets to demonstrate and reduce the issue area.

In the interim, what is a "valid subsegment name"? I've not seen any documented constraints about this and the SDK isn't checking anything. Is there a reference document that I missed?

[haotianw465]

Thank you for the clarification. We totally understand your use case and concerns here. You can check this documentation about the schema for segments/subsegments: https://docs.aws.amazon.com/xray/latest/devguide/xray-api-segmentdocuments.html and you can output your custom subsegments and use this reference to check if there is any issue with the custom subsegment documents.

If you have a function snippet that we can use to reproduce the issue you mentioned then we can do a deep dive here.

[nbeyer]

I'm still iterating on a smaller recreation of the issue, but I suspect it does have to do with the segment name and the use of a '#' character in the name. When I created some very simple lambdas, i was able to create segments and annotations in a variety of combinations, but noticed that I was using much more simple names (only A-Z and a-z). I went back to my larger system and removed references to '#', which reduced the characters use to be a-z, A-Z and '.', then everything started showing up as expected. According to the x-ray API documentation, I think '#' should be an allowed character.

[luluzhao]

Hello @nbeyer, I wrote a small test as you can see below.

func HandleRequest(ctx context.Context, name string) (string, error) {
    xray.Configure(xray.Config{LogLevel: "trace"})
    xray.Capture(ctx, "#ABC.abc#test", func(ctx1 context.Context) error {
        sess := session.Must(session.NewSession())
        dynamo := dynamodb.New(sess)
        xray.AWS(dynamo.Client)
        dynamo.ListTablesWithContext(ctx1, &dynamodb.ListTablesInput{})
        return nil
    })
    return fmt.Sprintf("Hello %s!", name), nil
}

func main() {
    lambda.Start(HandleRequest)
}

The test passed and I saw the trace document in X-Ray console and here I attached the partial subsegment below.

{
 "id": "c727e720444274b8",
 "name": "#ABC.abc#test",
 "start_time": 1527620575.3429537,
 "end_time": 1527620577.130815,
  "subsegments": [
         ....
}

As you can see, subsegment with '#' got accepted by X-Ray service. I am not sure what happened in your end but we definitely will help you figure out what issue is going on in your end. I remember you mentioned in previous reply said "I have the X-Ray SDK's logging on trace". If so, could you take a look at the logs to see whether the SDK generated the subsegment with '#' or not? If you enable "trace" level logging in SDK, you will be able to see the segment document before emitting. What's more, it would be great if you can provide the related code snippet so that we can reproduce in our side to see what is going on.

[spezam]

Hi @haotianw465,
I mention you since you are an AWS Xray engineer.

I feel the issue, along with #126 have been closed without providing a proper solution to integrate with Lambda.

In both case (xray.AddAnnotation() and xray.TraceID()) the suggested solution is to wrap these API calls in a placeholder Subsegment. While this works fine, I realized that it adds quite some garbage to the XRAy/Traces details.
Information that could be misleading to someone looking at the traces and not knowing about the code context.

Is there any plan at all to fix this?

Thanks,
Matteo

[willarmiros]

Hi @spezam,

Unfortunately there are no such plans on our roadmap at this time. This is because the segments generated for Lambda environments are not created by X-Ray, they are created on the backend of the Lambda service in a way that is agnostic of any X-Ray SDK. This is to provide a language-independent way of enabling X-Ray active tracing on Lambda functions without mandating each function depend on some X-Ray SDK.

The segments exposed to the actual Lambda function are called facade segments, since they are not actually the ones created by Lambda or transmitted to the X-Ray backend. Only subsegments created within the function are actually sent.

[spezam]

Thanks for the detailed explanation @willarmiros.

I guess the empty Subsegment will have to do.