open-telemetry / opentelemetry-python

OpenTelemetry Python API and SDK
https://opentelemetry.io
Apache License 2.0
1.67k stars 569 forks source link

Logged exception "Failed to detach context" when testing Flask app #3919

Open brianmcdonnell opened 1 month ago

brianmcdonnell commented 1 month ago

Describe your environment python 3.11 Flask==3.0.3 opentelemetry-distro==0.45b0

Steps to reproduce import unittest from flask import Flask from app import app as flask_app # Replace 'your_flask_app' with the actual name of your flask app file

Implement the simple opentelemetry getting started Flask app:

from random import randint
from flask import Flask, request
import logging

app = Flask(__name__)
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

@app.route("/rolldice")
def roll_dice():
    player = request.args.get('player', default=None, type=str)
    result = str(roll())
    if player:
        logger.warning("%s is rolling the dice: %s", player, result)
    else:
        logger.warning("Anonymous player is rolling the dice: %s", result)
    return result

def roll():
    return randint(1, 6)

Write a test for it, and run the test.

class FlaskAppTestCase(unittest.TestCase):
    def setUp(self):
        flask_app.testing = True

    def test_rolldice(self):
        with flask_app.test_client() as c:
            response = c.get('/rolldice')
        self.assertEqual(response.status_code, 200)

if __name__ == '__main__':
    unittest.main()

What is the expected behavior? I expected the test to pass without any exception logging to the console. Even though it might not be typical to use opentelemetry when running unit tests, I'd still expect it to work without noisy error messages.

What is the actual behavior? The test does pass, but it outputs noisy error messages.

ERROR:opentelemetry.context:Failed to detach context
Traceback (most recent call last):
  File "/Users/brianmcdonnell/src/otel-getting-started/venv/lib/python3.11/site-packages/opentelemetry/context/__init__.py", line 163, in detach
    _RUNTIME_CONTEXT.detach(token)  # type: ignore
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/brianmcdonnell/src/otel-getting-started/venv/lib/python3.11/site-packages/opentelemetry/context/contextvars_context.py", line 53, in detach
    self._current_context.reset(token)  # type: egnore
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: <Token used var=<ContextVar name='current_context' default={} at 0x106b1b830> at 0x107b8e980> has already been used once

Additional context This only happens when calling the test client from inside a with block. When the with block exits it tears down the context and logs this error. It appears that the opentelemetry Flask integration has already detached its context immediately after the request completed.