Later streamed subsegments are not in Xray about aws-xray-sdk-python HOT 6 CLOSED

The lambda function takes about 3.6-3.7 minutes with with active tracing on it. The second picture with the complete duration's warning symbol is because I was told the xray subsegments were sent in chunks. I wanted to see if there was something long running in the program, stoping information being sent before the lambda timed out, so after the last instruction I raised an error but the lambda did complete everything it supposed to do. Just an FYI.

from aws-xray-sdk-python.

Hi, thank you for reporting the issue. Could you provide a snapshot of what a problematic trace timeline looks like on X-Ray console so we can take a further look? Please feel free to redact any sensitive information.

Another question is that without instrumenting your lambda function code, how much time do you expect one execution takes?

from aws-xray-sdk-python.

@otterchurchill I'm having the same issue, how did you solve it?

from aws-xray-sdk-python.

Hi @safv12 ,

Would you mind providing more information on your case ? By looking at the information on comment looks like lambda function execution is completed before it could close the segment and toggle the in_progress flag so that could be the reason there is a pending segment on X-Ray console.

from aws-xray-sdk-python.

Hi @bhautikpip.

I was talking with the support center of AWS and they said that it is a size limit issue.

I just got an update from the X-ray service team. According to the trace data you provided, there are about 440 subsegments in a single segment my-segment-name which denotes the entire lambda function. The maximum size of a segment document can be 64KB as mentioned in the link https://docs.aws.amazon.com/xray/latest/devguide/xray-api-segmentdocuments.html . This is probably the issue here.

Thank you.

from aws-xray-sdk-python.

I believe we are running into this same issue and I wanted to point out that if this is a size limit issue it is not clear to me from the docs, which say (emphasis added):

A segment document can be up to 64 kB and contain a whole segment with subsegments, a fragment of a segment that indicates that a request is in progress, or a single subsegment that is sent separately.

and then later

A subsegment can be embedded in a full segment document or sent independently. Send subsegments separately to asynchronously trace downstream calls for long-running requests, or to avoid exceeding the maximum segment document size.

An example problematic x-ray trace looks like this for a lambda invocation that completed hours ago (note that we are using the x-ray sdk via the lambda powertools Tracer):

I have turned on debug logging, and the "Logs" box below the Segments Timeline above shows 163 lines from python logger aws_xray_sdk.core.emitters.udp_emitter. Whereas if I look through the actual lambda logs of the complete invocation there are 909 lines from this logger.

Looking through these log lines they all appear to be of the form:

{
    "timestamp": "2023-08-17T12:40:14.837121+0000", 
    "levelname": "DEBUG", 
    "name": "aws_xray_sdk.core.emitters.udp_emitter", 
    "message": "sending: {\"format\":\"json\",\"version\":1}\n{\"id\": \"******\", \"name\": \"logs\", \"start_time\": 1692276014.6623895, \"parent_id\": \"******\", \"in_progress\": false, \"http\": {\"response\": {\"status\": 200}}, \"aws\": {\"operation\": \"DescribeLogGroups\", \"region\": \"us-east-2\", \"request_id\": \"******\"}, \"trace_id\": \"******\", \"type\": \"subsegment\", \"namespace\": \"aws\", \"end_time\": 1692276014.8366702} to 169.254.79.129:2000.", 
    "aws_request_id": "*******"
}

The docs say

An independent subsegment has a type of subsegment, a trace_id, and a parent_id that identifies the parent segment.

So given the format of these messages I am inclined to believe these are independent subsegments which are being sent separately and therefore should "avoid exceeding the maximum segment document size."

But that is not the behavior I am seeing. If I pull out the json subsegment from the log and remove all whitespace:

{"id":"******","name":"logs","start_time":1692276014.6623895,"parent_id":"******","in_progress":false,"http":{"response":{"status":200}},"aws":{"operation":"DescribeLogGroups","region":"us-east-2","request_id":"******"},"trace_id":"******","type":"subsegment","namespace":"aws","end_time":1692276014.8366702}

This creates a string that is 387 characters long. Given that this is simple ASCII text this should correspond to 387 bytes in UTF-8.

Now taking the 163 debug lines I saw show up in the x-ray console: 387 * 163 = 63081

Or just under 64 KB.

Of course this is rough math because the subsegment documents are not all exactly the same, but it does support the idea that the maximum size of a segment document is 64 KB, regardless of whether the subsegments are sent separately or not. Which contradicts what the docs indicate.

Not sure where to raise this issue, I submitted feedback on that x-ray documentation page so hopefully that gets a response.

from aws-xray-sdk-python.