Skip to content

Conversation

basepi
Copy link
Contributor

@basepi basepi commented Oct 19, 2022

What does this pull request do?

Moves the end_transaction() into Starlette's ServerErrorMiddleware to solve #1110.

Big thanks to @magichair for help figuring this one out.

Related issues

Closes #1110

@ghost
Copy link

ghost commented Oct 19, 2022

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS
Pipeline View Test View Changes Artifacts preview preview

Expand to view the summary

Build stats

  • Start Time: 2022-10-25T19:22:05.180+0000

  • Duration: 16 min 57 sec

Test stats 🧪

Test Results
Failed 0
Passed 5060
Skipped 3461
Total 8521

💚 Flaky test report

Tests succeeded.

🤖 GitHub comments

Expand to view the GitHub comments

To re-run your PR in the CI, just comment with:

  • /test : Re-trigger the build.

  • /test linters : Run the Python linters only.

  • /test full : Run the full matrix of tests.

  • /test benchmark : Run the APM Agent Python benchmarks tests.

  • run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

@ghost
Copy link

ghost commented Oct 19, 2022

🌐 Coverage report

Name Metrics % (covered/total) Diff
Packages 100.0% (68/68) 💚
Files 100.0% (230/230) 💚
Classes 100.0% (230/230) 💚
Lines 91.042% (18181/19970) 👍 0.013
Conditionals 74.571% (2827/3791) 👍
@magichair
Copy link

magichair commented Oct 21, 2022

I've got a development environment setup from this branch too, I'm taking a look. So far I can see from the DEBUG lines that that __call__ method gets resolved and claims to get instrumented (and un-instrumented at test cleanup). But I am seeing the same behavior that it's seemingly never called.

edit:
By throwing some debug statements in, I can see that in the tests, the build_middleware_stack is called before the instrumentation happens. Does the monkey patching work on objects that have already been instantiated? I don't think so, right?
Answer: it's likely OK in this particular case since we're monkey patching ServerErrorMiddleware and in the build_middleware_stack reversed list it happens to re-instantiate after ElasticAPM instruments.

further edit:
Turns out, yes, you're spot on about __call__ being somehow special. I manually added an instrument_me() method on ServerErrorMiddleware, added that to the instrument_list and 🪄 tests pass!
I'm not sure where to go from here 🤔

ok, probably last edit for the day:
Comparing my two scenarios of instrumenting a real method (instrument_me()) vs. instrumenting the __call__. I am seeing that normal instrumentation gets through to:
https://github.com/elastic/apm-agent-python/blob/main/elasticapm/instrumentation/packages/base.py#L209-L210
But when it's trying the same for __call__ it ends up in the not transaction if:
https://github.com/elastic/apm-agent-python/blob/main/elasticapm/instrumentation/packages/base.py#L204-L205

I haven't dug further in than that, maybe this helps you with an "a-ha" moment, but I've definitely been pretty lost in all this wrapt magic.

@magichair
Copy link

Yup, ok, I'm pretty sure I fully understand here. The call_if_sampling is deciding whether to call the original method or call the wrapped method if we currently have a transaction recording. However, because we're trying to instrument the __call__ on ServerErrorMiddleware, that is the outermost middleware call, and our ElasticAPM middleware has not yet begin_transaction()'ed.

I think this really only leaves us with the option to force ElasticAPM to be the outermost in the middleware_stack. Unless y'all have some flag to tell the wrappers, "no, really, always instrument this regardless if we are in a transaction or not".

@basepi basepi marked this pull request as ready for review October 24, 2022 18:17
@basepi basepi requested a review from beniwohli October 24, 2022 18:17
Copy link
Contributor

@beniwohli beniwohli left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice solution!

@basepi basepi enabled auto-merge (squash) October 25, 2022 19:35
@basepi basepi disabled auto-merge October 25, 2022 19:36
@basepi basepi enabled auto-merge (squash) October 25, 2022 19:36
@basepi basepi merged commit e01327b into elastic:main Oct 25, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
3 participants