open-telemetry / open-telemetry/opentelemetry-python

pytest with `--log-cli-level=DEBUG` causes opentelemetry to fail

Open
#4,024 2 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Python
Stars
2.6k
Forks
1k
Avg merge
4d 15h
Merged PRs (30d)
19

Description

Describe your environment

OS: mac / docker ubuntu:latest
Python version: (e.g., Python 3.8.10) 3.12

What happened?

Unsure why this happens, but here is the A / B result

  • pytest using --log-cli-level=DEBUG causes opentelemetry to fail
  • pytest not using --log-cli-level=DEBUG everything works
Steps to Reproduce
Expected Result
  • expected pytest to run with DEBUG logs
Actual Result

TRACEBACK:

==================================== ERRORS ====================================
_ ERROR collecting automon/integrations/openTelemetryWrapper/test/test_pop_finished_spans.py _
automon/integrations/openTelemetryWrapper/test/test_pop_finished_spans.py:7: in <module>
    class MyTestCase(unittest.TestCase):
automon/integrations/openTelemetryWrapper/test/test_pop_finished_spans.py:11: in MyTestCase
    test = asyncio.run(config.test())
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/asyncio/runners.py:190: in run
    return runner.run(main)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/asyncio/runners.py:118: in run
    return self._loop.run_until_complete(task)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/asyncio/base_events.py:654: in run_until_complete
    return future.result()
automon/integrations/openTelemetryWrapper/config.py:55: in test
    with self.tracer.start_as_current_span(name="childSpan") as trace_child:
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/contextlib.py:144: in __exit__
    next(self.gen)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/opentelemetry/_trace.py:148: in start_as_current_span
    with use_span(
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/contextlib.py:144: in __exit__
    next(self.gen)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/trace/__init__.py:600: in use_span
    span.end()
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/opentelemetry/_span.py:[126](https://github.com/TheShellLand/automonisaur/actions/runs/9789509443/job/27029522812#step:6:127): in end
    self._ddspan._finish_ns(end_time)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/_trace/span.py:326: in _finish_ns
    cb(self)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/_trace/tracer.py:828: in _on_span_finish
    log.debug("span %r closing after its parent %r, this is an error when not using async", span, span._parent)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py:1477: in debug
    self._log(DEBUG, msg, args, **kwargs)
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py:1632: in _log
    record = self.makeRecord(self.name, level, fn, lno, msg, args,
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py:1601: in makeRecord
    rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func,
/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/instrumentation/logging/__init__.py:117: in record_factory
    record.otelTraceSampled = ctx.trace_flags.sampled
E   AttributeError: 'int' object has no attribute 'sampled'
------------------------------- Captured stderr --------------------------------
Description None ignored. Use either `Status` or `(StatusCode, Description)`
trace 136278351292336987527269310340925836173 has 2 spans, 1 finished
finishing span name='internal' id=1415639[128](https://github.com/TheShellLand/automonisaur/actions/runs/9789509443/job/27029522812#step:6:129)5474623600 trace_id=136278351292336987527269310340925836173 parent_id=None service=None resource='rootSpan' type=None start=1720074617.401013 end=1720074617.4576619 duration=0.05664904 error=1 tags={'error.message': "AttributeError: 'int' object has no attribute 'sampled'", 'error.stack': 'Traceback (most recent call last):\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/trace/__init__.py", line 573, in use_span\n    yield span\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/opentelemetry/_trace.py", line 154, in start_as_current_span\n    yield span\n  File "/home/runner/work/automonisaur/automonisaur/automon/integrations/openTelemetryWrapper/config.py", line 55, in test\n    with self.tracer.start_as_current_span(name="childSpan") as trace_child:\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/contextlib.py", line 144, in __exit__\n    next(self.gen)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/opentelemetry/_trace.py", line 148, in start_as_current_span\n    with use_span(\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/contextlib.py", line [144](https://github.com/TheShellLand/automonisaur/actions/runs/9789509443/job/27029522812#step:6:145), in __exit__\n    next(self.gen)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/trace/__init__.py", line 600, in use_span\n    span.end()\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/opentelemetry/_span.py", line 126, in end\n    self._ddspan._finish_ns(end_time)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/_trace/span.py", line 326, in _finish_ns\n    cb(self)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/ddtrace/_trace/tracer.py", line 828, in _on_span_finish\n    log.debug("span %r closing after its parent %r, this is an error when not using async", span, span._parent)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py", line [147](https://github.com/TheShellLand/automonisaur/actions/runs/9789509443/job/27029522812#step:6:148)7, in debug\n    self._log(DEBUG, msg, args, **kwargs)\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py", line 1632, in _log\n    record = self.makeRecord(self.name, level, fn, lno, msg, args,\n             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/logging/__init__.py", line 1601, in makeRecord\n    rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func,\n         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File "/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/instrumentation/logging/__init__.py", line 117, in record_factory\n    record.otelTraceSampled = ctx.trace_flags.sampled\n                              ^^^^^^^^^^^^^^^^^^^^^^^\nAttributeError: \'int\' object has no attribute \'sampled\'\n', 'error.type': 'builtins.AttributeError', 'runtime-id': '89570a6208054e33a463433e38a33bf4'} metrics={'_dd.top_level': 1, 'process_id': 2302} (enabled:True)
=========================== short test summary info ============================
ERROR automon/integrations/openTelemetryWrapper/test/test_pop_finished_spans.py - AttributeError: 'int' object has no attribute 'sampled'
!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!
=============================== 1 error in 9.69s ===============================
Error: Process completed with exit code 2.
Additional context

ERROR:

/opt/hostedtoolcache/Python/3.11.9/x64/lib/python3.11/site-packages/opentelemetry/instrumentation/logging/__init__.py:117: in record_factory
    record.otelTraceSampled = ctx.trace_flags.sampled
E   AttributeError: 'int' object has no attribute 'sampled'
Would you like to implement a fix?

None

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reproducing the failure with pytest --log-cli-level=DEBUG and inspect automon/integrations/openTelemetryWrapper/test/test_pop_finished_spans.py and config.py. Trace the interaction with opentelemetry/instrumentation/logging/init.py:117. Done means test collection and the affected test complete successfully with DEBUG logging enabled.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
observability-sre
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.