observability: annotate Session+SessionPool events by odeke-em · Pull Request #1207 · googleapis/python-spanner · GitHub

This change adds annotations for session and session pool events to aid customers in debugging latency issues with session pool malevolence and also for maintainers to figure out which session pool type is the most appropriate.

Updates #1170

BEGIN_COMMIT_OVERRIDE
feat: add additional opentelemetry span events for session pool
END_COMMIT_OVERRIDE

Exhibit

On running examples/grpc_instrumentation_enabled.py we get back these traces

cc @harshachinta

Kindly cc-ing you @harshachinta.

Kindly please take another look @harshachinta, feedback addressed, thank you for the code review!

current_span is not initialized.

Sheesh, sorry I had a bunch of benchmarks running locally and they interrupted my nox -s unit-3.8 tests so didn't see those but all fixed now.

Suggested change

      
                        if self._transaction_id is None and len(self._mutations) > 0:
          
                            self.begin()

Why is this added here? This is already getting executed in the beginning of commit() call, so not needed

python-spanner/google/cloud/spanner_v1/transaction.py

Line 237 in 054a186

if self._transaction_id is None and len(self._mutations) > 0:

Suggested change

      
                        add_span_event(current_span, "No session available", span_event_attributes)
          
                        add_span_event(current_span, "No session available in the pool", span_event_attributes)

why are there 2 exception events?

It is a quirk with opentelemetry-python; they add "exception" on every exit call whether or not you set your own, I'll file a bug later on but for now I'll just remove our explicit invocation of "span.record_exception" and instead add our comment.

Thank you @harshachinta for the review, I've addressed the feedback. Please take a look again.

@harshachinta kindly help me run the bots.

Please fix lint

Lets not remove this exception. We are not sure if there are any cases where the span will end up not recording an exception.
I would suggest adding this back here and let us discuss more during our demo.

Also I was wondering that this behavior of exception getting added twice was not seen earlier since this code exists from very long.

It's because OpenTelemetry was upgraded only recently.

We do have locked tests to check for the exceptions to ensure that they are in there and from Span.enter. I had to dive back into OpenTelemetry-Python's code as it isn't even documented and in our demos it was very distracting to have mysteriously both errors. I think for the sake of our sanity and project stability let's leave that comment in and if anything happens it is a trivial one to add back @harshachinta

Hmm. But the opentelemetry documentation for Python guides to record exception for instrumentation libraries.
https://opentelemetry.io/docs/languages/python/instrumentation/#record-exceptions-in-spans

Can you share the code pointer on where the opentelemetry records exception by default when exiting?

@harshachinta https://github.com/open-telemetry/opentelemetry-python/blob/db4ef06f471cb9e94d810ae66964c3e5e0f5e61e/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py#L986-L1008

@harshachinta it was the cause of us seeing 2 exceptions and took a ton of confusion and time for me to debug, they don't seem to document this condition.

@harshachinta kindly help me re-run the bots; all unit tests pass locally.

This change adds annotations for session and session pool events to aid customers in debugging latency issues with session pool malevolence and also for maintainers to figure out which session pool type is the most appropriate. Updates googleapis#1170

odeke-em requested review from a team September 19, 2024 03:48

product-auto-label Bot added the size: m Pull request size is medium. label Sep 19, 2024

blunderbuss-gcf Bot assigned manu2 Sep 19, 2024

product-auto-label Bot added the api: spanner Issues related to the googleapis/python-spanner API. label Sep 19, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch 3 times, most recently from 8d6f2b7 to 4bc937e Compare September 19, 2024 07:37

odeke-em force-pushed the trace-annotation-SessionPools branch from 4bc937e to 0d5bf26 Compare September 19, 2024 07:45

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 19, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 19, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch from 0d5bf26 to 3617921 Compare September 19, 2024 13:43

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 19, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 19, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch 2 times, most recently from f71d05c to eb9dd5a Compare September 20, 2024 01:27

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 20, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 20, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch from b1ea772 to ab23f09 Compare September 20, 2024 22:09

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 23, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Sep 23, 2024

harshachinta suggested changes Oct 1, 2024

View reviewed changes

odeke-em requested a review from harshachinta October 7, 2024 02:36

harshachinta reviewed Oct 9, 2024

View reviewed changes

Comment thread google/cloud/spanner_v1/_opentelemetry_tracing.py Outdated

harshachinta reviewed Oct 9, 2024

View reviewed changes

Comment thread google/cloud/spanner_v1/pool.py Outdated

harshachinta reviewed Oct 9, 2024

View reviewed changes

odeke-em force-pushed the trace-annotation-SessionPools branch from e60b662 to 3a1611e Compare November 27, 2024 04:08

harshachinta reviewed Nov 28, 2024

View reviewed changes

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 28, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 28, 2024

odeke-em requested a review from harshachinta November 28, 2024 14:08

odeke-em force-pushed the trace-annotation-SessionPools branch from b6187d8 to e654029 Compare November 28, 2024 14:26

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 28, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 28, 2024

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 29, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Nov 29, 2024

harshachinta approved these changes Nov 29, 2024

View reviewed changes

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 2, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 2, 2024

harshachinta reviewed Dec 2, 2024

View reviewed changes

Comment thread tests/unit/test_pool.py

sakthivelmanii added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 2, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 2, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch from 498a70a to 060d17c Compare December 3, 2024 10:04

harshachinta added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 3, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 3, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch from 060d17c to b400718 Compare December 5, 2024 10:31

sakthivelmanii added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 5, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 5, 2024

odeke-em force-pushed the trace-annotation-SessionPools branch from b400718 to 1d7e440 Compare December 6, 2024 07:54

rahul2393 added the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 6, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Dec 6, 2024

harshachinta merged commit a6811af into googleapis:main Dec 6, 2024

                           yield span
                       except Exception as error:
                           span.set_status(Status(StatusCode.ERROR, str(error)))
-                          span.record_exception(error)

+                          )
+                          if requested_session_count > 0:
+                              current_span.add_event(

		if self._transaction_id is None and len(self._mutations) > 0:
		self.begin()

+                          )
+                          session = self._sessions.get(block=True, timeout=timeout)
+                      except queue.Empty as e:
+                          add_span_event(current_span, "No session available", span_event_attributes)

	add_span_event(current_span, "No session available", span_event_attributes)
	add_span_event(current_span, "No session available in the pool", span_event_attributes)

		"exception",
		"exception",

observability: annotate Session+SessionPool events by odeke-em · Pull Request #1207 · googleapis/python-spanner · GitHub

Uh oh!

observability: annotate Session+SessionPool events - #1207

observability: annotate Session+SessionPool events#1207harshachinta merged 1 commit intogoogleapis:maingoogleapis/python-spanner:mainfrom odeke-em:trace-annotation-SessionPoolsodeke-em/python-spanner:trace-annotation-SessionPoolsCopy head branch name to clipboard

Conversation

odeke-em commented Sep 19, 2024 • edited by harshachinta Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

odeke-em commented Sep 19, 2024

Exhibit

Uh oh!

odeke-em commented Sep 19, 2024

Uh oh!

odeke-em commented Sep 20, 2024

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

odeke-em commented Oct 7, 2024

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

odeke-em commented Nov 28, 2024

Uh oh!

odeke-em commented Nov 29, 2024

Uh oh!

harshachinta left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

odeke-em commented Dec 2, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

6 participants

observability: annotate Session+SessionPool events#1207
harshachinta merged 1 commit into
googleapis:mainfrom
odeke-em:trace-annotation-SessionPools

odeke-em commented Sep 19, 2024 •
edited by harshachinta
Loading