Exception thrown when Lambda is not initialized in begin_subsegment

[chanchiem]

When Lambda is not initialized in begin_subsegment(), an exception is thrown because the global SDK config module was improperly named.

[ShehryarKh]

@chanchiem
Hi, I am still seeing this bug when running locally.

running a flask application
/init.py

from aws_xray_sdk.core import xray_recorder

xray_recorder.configure(
    sampling=False,
    context_missing='LOG_ERROR',
    daemon_address='x-ray-daemon:2000'
)

/app.py

from bla import xray_recorder

xray_recorder.capture('form')
def form():
    do something

/docker-compose.yml

services:
  x-ray-daemon:
    image: amazon/aws-xray-daemon
    ports:
      - "2000:2000/udp"
    networks:
      - zapi
    volumes:
      - ~/.aws/:/root/.aws/:ro
    environment:
      - AWS_REGION=us-east-1

/Pipfile

aws-xray-sdk = "~=2.3.0"

response when I call my api locally

segment form discarded due to Lambda worker still initializing

the full application is inside of docker. When I rundocker-compose up
I see x-ray-daemon_1 | 2019-02-14T20:41:50Z [Info] Initializing AWS X-Ray daemon 3.0.0

any idea?

[chanchiem]

Hey, this issue is different from the issue that you're experiencing. This issue is specific to an exception thrown as a result of the misnamed global configuration.

It looks like the issue you're having could be happening due to two things:

1. Running Flask on Lambda is not yet supported. The solution you have is to log the FacadeSegmentException, and this can cause potential errors if your middleware attempts to begin a segment.
2. The container did not yet finish initializing, so the underlying facade segment has not been generated yet.

Some follow up questions:

• Are you running this docker inside Lambda?
• Is this happening every time you run your code or is it probabilistic?
• When you are calling your API locally, are you running it on your local machine or running it on a tool like AWS SAM to run Lambda locally?

[ShehryarKh]

Hey, yes I'm running the API locally on my machine. It is occurring every time. Also not I am not running the docker inside lambda. If I push up my code, I can see the traces/segments working, just unable to test it locally.

[chanchiem]

So are you running it locally through a tool like AWS SAM or your local machine?

If completely local, it confuses me why you would see this log error because this only happens if your recorder is using the Lambda Context.

Are you explicitly setting the context somewhere to use the Lambda Context?
Something like:

from aws_xray_sdk.core import xray_recorder, lambda_launcher

xray_recorder.configure(
  context=lambda_launcher.LambdaContext()
)

# or the following
xray_recorder.context = lambda_launcher.LambdaContext()

[ShehryarKh]

no, I am not. It's completely local. If I follow the steps of Running the X-Ray Daemon in a Docker Container, the following occurs

aws-xray-daemon-macos-3.x ./xray_mac -o -n us-east-1
2019-02-14T12:39:22-05:00 [Info] Initializing AWS X-Ray daemon 3.0.0
2019-02-14T12:39:22-05:00 [Info] Using buffer memory limit of 100 MB
2019-02-14T12:39:22-05:00 [Info] 1600 segment buffers allocated
2019-02-14T12:39:22-05:00 [Info] Using region: us-east-1
2019-02-14T12:39:22-05:00 [Info] Starting proxy http server on 127.0.0.1:2000

It seems to just stay at Starting proxy http server on 127.0.0.1:2000

can that be part of the issue?

[chanchiem]

Hmm it shouldn't be the issue because the SDK doesn't actually get information back from the Daemon. It sends the trace information through UDP, so it's sort of send it and forget it.

Can you try explicitly setting the context on your local build with a configuration that explicitly uses the default Context and report to me the results?

from aws_xray_sdk.core import xray_recorder
from aws_xray_sdk.core.context import Context

xray_recorder.configure(
# Add your other configuration information as well
  context=Context()
)

[ShehryarKh]

okay do I did this:
/init.py

from aws_xray_sdk.core import xray_recorder
from aws_xray_sdk.core.context import Context

xray_recorder.configure(
    sampling=False,
    context_missing='LOG_ERROR',
    daemon_address='x-ray-daemon:2000',
    context=Context()
)

/app.py

from bla import xray_recorder

@xray_recorder.capture('form_submit')
def form_submit()
    do something

this is returning

cannot find the current segment/subsegment, please make sure you have a segment open
| No segment found, cannot begin subsegment form_submit.

[chanchiem]

Okay cool, it looks like we found the root of the problem. It looks like when you are running it locally, your application is using the Lambda Context when it's not supposed to. I would investigate to see if any of your code modifies the recorder's Context property manually.

This would make sense why it think the segment is still being initialized--because it never will actually finish. Now, you mention that you're using Flask as your web framework, but I don't see how you are invoking it. Please make sure to run X-Ray's middleware patcher on it for it to instrument requests:
https://docs.aws.amazon.com/xray/latest/devguide/xray-sdk-python-middleware.html#xray-sdk-python-adding-middleware-flask

As for the following error:

cannot find the current segment/subsegment, please make sure you have a segment open
| No segment found, cannot begin subsegment form_submit.

This happens because your middleware isn't being instrumented. The capture annotation automatically generates subsegments whenever the method is called. You need to create a segment prior to calling that. Normally, the middleware would do this automatically.

[ShehryarKh]

Perfect, I was missing the X-Ray middleware. Even though I'm now getting no error, I also see nothing happening...

/init.py

from aws_xray_sdk.core.context import Context
from aws_xray_sdk.core import xray_recorder
from aws_xray_sdk.ext.flask.middleware import XRayMiddleware
...
app = Flask(__name__)

xray_recorder.configure(
    sampling=False,
    daemon_address='127.0.0.1:2000',
    context_missing='LOG_ERROR',
    service='my-app',
    context=Context()
)

XRayMiddleware(app, xray_recorder)
...

/app.py

from bla import xray_recorder
...
@xray_recorder.capture('form_submit')
def form_submit():
    do something

Im running the xray in a seprate docker.

➜  aws-xray-daemon-macos-3.x ./xray_mac -o -n us-east-1
2019-02-14T22:05:42-05:00 [Info] Initializing AWS X-Ray daemon 3.0.0
2019-02-14T22:05:42-05:00 [Info] Using buffer memory limit of 100 MB
2019-02-14T22:05:42-05:00 [Info] 1600 segment buffers allocated
2019-02-14T22:05:42-05:00 [Info] Using region: us-east-1
2019-02-14T22:05:42-05:00 [Info] Starting proxy http server on 127.0.0.1:2000

Is there a way to see whats going on?

I tried adding

@xray_recorder.capture('form_submit')
def form_submit():
    do something
    ....
    subsegment = xray_recorder.begin_subsegment('user id')
    ...
    subsegment.put_metadata('identity', identity)
    xray_recorder.end_subsegment(subsegment)

I get

auth-app_1      | [2019-02-15 18:12:25,480] INFO in test: 
auth-app_1      | cannot find the current segment/subsegment, please make sure you have a segment open
auth-app_1      | No subsegment to end.
...
AttributeError: 'NoneType' object has no attribute 'put_http_meta'

[ShehryarKh]

@chanchiem hey sorry, do you have any suggestions on this, I'm still stuck here. I don't see how my code is modifying the recorder's Context property manually.

[chanchiem]

Are you running this in Lambda? Configuring the recorder to explicitly use Context() would only work if you are running it on your local build. I would recommend removing it if you are running it on Lambda, as it is not designed to work with it.

Although this is probably not the root cause of your issue, but setting the sampling decision explicitly to False would ensure that traces won't be sent to the Daemon. If you set it to True, all traces will be sent to the Daemon. If you want to invoke the default sampling rules, not setting it would do that.

I think the root of your problem is that the method isn't being invoked using the middleware. As you could see from your log, whenever the method attempts to begin a subsegment, there isn't a segment to store the subsegment in, and since your context_missing strategy is to log, it won't throw an exception and therefore also not generate a segment if an error occured. Usually, with a Middleware like Flask, the way to invoke the X-Ray middleware to instrument the segment, you would do something like:

@app.route('/some_endpoint')
def process_request():
    form_submit()

Is this precisely what you are doing? If your form_submit() method call is not invoked by a the middleware, then what I would recommend doing is surrounding the call with a segment like below:

xray_recorder.begin_segment("form_submit")
form_submit()
xray_recorder.end_segment()

Also, I've noticed that you have submitted a forum post:
https://forums.aws.amazon.com/thread.jspa?threadID=298523&tstart=0

My apologies for not responding to it sooner. I must have missed it. It would be much better if we can move this conversation to that forum post for the sake of public exposure so that others who may encounter this kind of issue may also benefit as opposed to seeing it on a closed Github issue.

[ShehryarKh]

Great, I updated the question, thank you

[chanchiem]

Update in case any one is having similar issues:

Turns out that the middleware being used was Connexion, a web framework built on top of Flask. The Flask middleware patcher even for Connexion's underlying Flask App cannot be patched to work with X-Ray because it uses different mechanisms to handle the endpoint requests.

We don't currently have support for this framework yet, but an issue has been opened up requesting for support. (#133)