solution and test for tracer multi-import issue (#161)

* solution and test for tracer multi-import issue

* vbump and fmt

* fixed test failure

* addressed pr comments

* new linter

lib/charms/tempo_k8s/v1/charm_tracing.py

@@ -224,7 +224,6 @@ def _remove_stale_otel_sdk_packages():
 
 _remove_stale_otel_sdk_packages()
 
-
 import functools
 import inspect
 import logging
@@ -271,7 +270,7 @@ def _remove_stale_otel_sdk_packages():
 # Increment this PATCH version before using `charmcraft publish-lib` or reset
 # to 0 if you are raising the major API version
 
-LIBPATCH = 14
+LIBPATCH = 15
 
 PYDEPS = ["opentelemetry-exporter-otlp-proto-http==1.21.0"]
 
@@ -281,7 +280,6 @@ def _remove_stale_otel_sdk_packages():
 # set this to 0 if you are debugging/developing this library source
 dev_logger.setLevel(logging.CRITICAL)
 
-
 _CharmType = Type[CharmBase]  # the type CharmBase and any subclass thereof
 _C = TypeVar("_C", bound=_CharmType)
 _T = TypeVar("_T", bound=type)
@@ -333,9 +331,22 @@ def _get_tracer() -> Optional[Tracer]:
     try:
         return tracer.get()
     except LookupError:
+        # fallback: this course-corrects for a user error where charm_tracing symbols are imported
+        # from different paths (typically charms.tempo_k8s... and lib.charms.tempo_k8s...)
         try:
             ctx: Context = copy_context()
             if context_tracer := _get_tracer_from_context(ctx):
+                logger.warning(
+                    "Tracer not found in `tracer` context var. "
+                    "Verify that you're importing all `charm_tracing` symbols from the same module path. \n"
+                    "For example, DO"
+                    ": `from charms.lib...charm_tracing import foo, bar`. \n"
+                    "DONT: \n"
+                    " \t - `from charms.lib...charm_tracing import foo` \n"
+                    " \t - `from lib...charm_tracing import bar` \n"
+                    "For more info: https://python-notes.curiousefficiency.org/en/latest/python"
+                    "_concepts/import_traps.html#the-double-import-trap"
+                )
                 return context_tracer.get()
             else:
                 return None

src/charm.py

@@ -35,6 +35,7 @@
 from ops.main import main
 from ops.model import ActiveStatus, BlockedStatus, MaintenanceStatus, WaitingStatus
 from ops.pebble import APIError
+
 from tempo import Tempo
 
 logger = logging.getLogger(__name__)

tests/integration/test_ingressed_tls.py

@@ -10,9 +10,9 @@
 import requests
 import yaml
 from pytest_operator.plugin import OpsTest
-from tempo import Tempo
 from tenacity import retry, stop_after_attempt, wait_exponential
 
+from tempo import Tempo
 from tests.integration.helpers import get_relation_data
 
 METADATA = yaml.safe_load(Path("./charmcraft.yaml").read_text())

tests/integration/test_tls.py

@@ -10,9 +10,9 @@
 import requests
 import yaml
 from pytest_operator.plugin import OpsTest
-from tempo import Tempo
 from tenacity import retry, stop_after_attempt, wait_exponential
 
+from tempo import Tempo
 from tests.integration.helpers import get_relation_data
 
 METADATA = yaml.safe_load(Path("./charmcraft.yaml").read_text())

tests/interface/conftest.py

@@ -3,12 +3,13 @@
 from unittest.mock import patch
 
 import pytest
-from charm import TempoCharm
 from charms.tempo_k8s.v1.charm_tracing import charm_tracing_disabled
 from interface_tester import InterfaceTester
 from ops.pebble import Layer
 from scenario.state import Container, State
 
+from charm import TempoCharm
+
 
 # Interface tests are centrally hosted at https://github.com/canonical/charm-relation-interfaces.
 # this fixture is used by the test runner of charm-relation-interfaces to test tempo's compliance

tests/scenario/conftest.py

@@ -1,9 +1,10 @@
 from unittest.mock import patch
 
 import pytest
-from charm import TempoCharm
 from scenario import Context
 
+from charm import TempoCharm
+
 
 @pytest.fixture
 def tempo_charm():

tests/scenario/helpers.py

@@ -2,6 +2,7 @@
 
 import scenario
 import yaml
+
 from tempo import Tempo
 
 

tests/scenario/test_a_charm_tracer_multi_import_warning.py

@@ -0,0 +1,67 @@
+# WARNING ensure that this test module runs before any other scenario test file, else the
+# imports from previous tests will pollute the sys.modules and cause this test to fail.
+# I know this is horrible but yea, couldn't find a better way to fix the issue. Tried:
+# - delete from sys.modules all modules containing 'charms.tempo_k8s'
+# - delete from sys.modules all modules containing 'otlp_http'
+
+
+from unittest.mock import patch
+
+# this test file is intentionally quite broken, don't modify the imports
+# import autoinstrument from charms.[...]
+from charms.tempo_k8s.v1.charm_tracing import _autoinstrument as autoinstrument
+from ops import CharmBase
+from scenario import Context, State
+
+# import trace from lib.charms.[...]
+from lib.charms.tempo_k8s.v1.charm_tracing import trace
+
+
+@trace
+def _my_fn(foo):
+    return foo + 1
+
+
+class MyCharmSimpleEvent(CharmBase):
+    META = {"name": "margherita"}
+
+    def __init__(self, fw):
+        super().__init__(fw)
+        fw.observe(self.on.start, self._on_start)
+
+    def _on_start(self, _):
+        _my_fn(2)
+
+    @property
+    def tempo(self):
+        return "foo.bar:80"
+
+
+autoinstrument(MyCharmSimpleEvent, "tempo")
+
+
+def test_charm_tracer_multi_import_warning(caplog, monkeypatch):
+    """Check that we warn the user in case the test is importing tracing symbols from multiple paths.
+
+    See https://python-notes.curiousefficiency.org/en/latest/python_concepts/import_traps.html#the-double-import-trap
+    for a great explanation of what's going on.
+    """
+    import opentelemetry
+
+    with patch(
+        "opentelemetry.exporter.otlp.proto.http.trace_exporter.OTLPSpanExporter.export"
+    ) as f:
+        f.return_value = opentelemetry.sdk.trace.export.SpanExportResult.SUCCESS
+        ctx = Context(MyCharmSimpleEvent, meta=MyCharmSimpleEvent.META)
+        with caplog.at_level("WARNING"):
+            ctx.run("start", State())
+
+        spans = f.call_args_list[0].args[0]
+        assert [span.name for span in spans] == [
+            # we're only able to capture the _my_fn span because of the fallback behaviour
+            "function call: _my_fn",
+            "method call: MyCharmSimpleEvent._on_start",
+            "event: start",
+            "margherita/0: start event",
+        ]
+        assert "Tracer not found in `tracer` context var." in caplog.records[0].message

tests/scenario/test_charm.py

@@ -9,8 +9,8 @@
 from scenario import Container, Mount, Relation, State
 from scenario.sequences import check_builtin_sequences
 from scenario.state import Notice, _BoundNotice
-from tempo import Tempo
 
+from tempo import Tempo
 from tests.scenario.helpers import get_tempo_config
 
 TEMPO_CHARM_ROOT = Path(__file__).parent.parent.parent

tests/scenario/test_charm_tracing.py

@@ -5,7 +5,7 @@
 
 import pytest
 import scenario
-from charms.tempo_k8s.v1.charm_tracing import CHARM_TRACING_ENABLED
+from charms.tempo_k8s.v1.charm_tracing import CHARM_TRACING_ENABLED, get_current_span, trace
 from charms.tempo_k8s.v1.charm_tracing import _autoinstrument as autoinstrument
 from charms.tempo_k8s.v2.tracing import (
     ProtocolType,
@@ -19,8 +19,6 @@
 from scenario import Context, State
 from scenario.runtime import UncaughtCharmError
 
-from lib.charms.tempo_k8s.v1.charm_tracing import get_current_span, trace
-
 os.environ[CHARM_TRACING_ENABLED] = "1"
 
 logger = logging.getLogger(__name__)

tests/scenario/test_ingressed_tracing.py

@@ -4,6 +4,7 @@
 import yaml
 from charms.tempo_k8s.v1.charm_tracing import charm_tracing_disabled
 from scenario import Container, Relation, State
+
 from tempo import Tempo
 
 

tests/scenario/test_tls.py

@@ -2,11 +2,12 @@
 from unittest.mock import patch
 
 import pytest
-from charm import Tempo
 from charms.tempo_k8s.v1.charm_tracing import charm_tracing_disabled
 from charms.tempo_k8s.v2.tracing import TracingProviderAppData, TracingRequirerAppData
 from scenario import Container, Relation, State
 
+from charm import Tempo
+
 
 @pytest.fixture
 def base_state():

tests/scenario/test_tracing_requirer.py

@@ -10,6 +10,7 @@
 )
 from ops import CharmBase, Framework, RelationBrokenEvent, RelationChangedEvent
 from scenario import Context, Relation, State
+
 from tempo import Tempo
 
 

tests/unit/test_charm.py

@@ -6,10 +6,11 @@
 import unittest
 from unittest.mock import patch
 
-from charm import TempoCharm
 from ops.model import ActiveStatus
 from ops.testing import Harness
 
+from charm import TempoCharm
+
 CONTAINER_NAME = "tempo"
 
 

tests/unit/test_tempo.py

@@ -1,6 +1,7 @@
 from unittest.mock import patch
 
 import pytest
+
 from tempo import Tempo