Using tracer.start_as_current_span() manually without 'with' context manager leads to error

[hashcutdev]

I have a situation where I can't use the usual with tracer.start_as_current_span("foo") as span: construct. So instead, I'd like to manually handle calling __enter__() and __exit__() myself. However, when I do that, the span is started and instantly ended, and no attributes or anything else can be added as the span is immediately ended, even before I call __exit__().

Describe your environment Python v3.8.8 opentelemetry-api 1.11.1 opentelemetry-exporter-jaeger-thrift 1.11.1 opentelemetry-sdk 1.11.1 opentelemetry-semantic-conventions 0.30b1 (installed from conda-forge)

Steps to reproduce

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import (
    ConsoleSpanExporter,
    SimpleSpanProcessor,
)
import time

trace.set_tracer_provider(TracerProvider())
trace.get_tracer_provider().add_span_processor(
    SimpleSpanProcessor(ConsoleSpanExporter())
)

tracer = trace.get_tracer(__name__)

with tracer.start_as_current_span("foo") as span:
    span.set_attribute("foo", "bar")
    time.sleep(1)

span = tracer.start_as_current_span("foo").__enter__()
span.set_attribute("foo", "bar")
time.sleep(1)
span.__exit__(None, None, None)

What is the expected behavior? The two spans should be identical (aside from timestamps, which should be 1 second between start and end)

What is the actual behavior? As seen below, with the second span, there's no 1 sec interval between the start_time and end_time, and the attributes are empty

{
    "name": "foo",
    "context": {
        "trace_id": "0x7c8f5bfd12f479322fd8fe1a3b878b7f",
        "span_id": "0xa022a97ae4ec3ba6",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": null,
    "start_time": "2022-06-28T23:20:42.362582Z",
    "end_time": "2022-06-28T23:20:43.363672Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "foo": "bar"
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.11.1",
        "service.name": "unknown_service"
    }
}
{
    "name": "foo",
    "context": {
        "trace_id": "0xdefed7453f0fbd25d20cef3858dbf4cd",
        "span_id": "0xfb6f62c513082941",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": null,
    "start_time": "2022-06-28T23:20:43.364254Z",
    "end_time": "2022-06-28T23:20:43.364275Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {},
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.11.1",
        "service.name": "unknown_service"
    }
}
Setting attribute on ended span.
Calling end() on an ended span.

Additional context I'm using start_as_current_span() so that I don't have to manage the context, and I can allow subroutines within the __enter__() and __exit__() block to create child spans. I'm willing to use a different method if needed, and manage the context myself. But I'm puzzled why manually calling the context methods should lead to different results. My understanding is that this is all that the with expression does anyway?

[ronnathaniel]

This already exists under a different syntax with context mgmt:

ctx = trace.set_span_in_context(None)
child = tracer.start_span("child", context=ctx)
try:
    print('hello world')
finally:
    child.end()

[aabmass]

@hashcutdev, @ronnathaniel answer is correct, you can use the start_span() API directly without the context manager.

[rayrapetyan]

For me:

tracer.start_span("child", context=ctx)

construction is not equal to using:

with tracer.start_as_current_span:

The difference is - in tempo logs automated and manual traces appear as separate entities in the first case (start_span), and as a single record (as expected) in the second case (start_as_current_span).

So the question still remains - how to simulate start_as_current_span without with? Thanks.

[rafalp]

@rayrapetyan when you create your span with start_span, you are creating span that's detached from context. So you need to tell its children explicitly about it:

parent = tracer.start_span("parent", context=ctx)
parent_context = set_span_in_context(parent)

# Elsewhere in the code
with tracer.start_span("child", context=context):
   ...

I've found that here.

[hterik]

Did anyone find a neat solution for this? The problem with start_as_current_span is that the return value is a GeneratorContextManager object, that calls __exit__ inside its __del__ function. Unlike the Span instance returned in __enter__. Making the first one dispose and end even before Span.__exit__ is reached if you try to use it without with-statement.

To make it work you have to keep the GeneratorContextManager variable alive until you are ready to end the span, which is rather ugly.

[aabmass]

There are two separate concepts here

1. Setting the span in OpenTelemetry's current implicit context. Doing this causes any new spans to automatically become a child, without having to pass a context like https://github.com/open-telemetry/opentelemetry-python/issues/2787#issuecomment-1568711715.
2. Ending the span. This controls the end timestamps we set on the span and when your span is passed to the SpanProcessor's on_end() method

Both start_span and start_as_current_span handle ending the span for you (unless you pass end_on_exit=False). start_as_current_span also sets the span in current implicit context within the with body.

---

This example shows the primitives so you can do whatever you need:

from opentelemetry import trace, context

# Start parent
parent = tracer.start_span("parent")

# Creates a Context object with parent set as current span
ctx = trace.set_span_in_context(parent)

# Set as the implicit current context
token = context.attach(ctx)

# Child will automatically be a child of parent
child1 = tracer.start_span("child1")
child1.end()

# Child will automatically be a child of parent
child2 = tracer.start_span("child2")
child2.end()

# Don't forget to detach or parent will remain the parent above this call stack
context.detach(token)
parent.end()

which is equivalent to

with tracer.start_as_current_span("parent") as parent:
    with tracer.start_span("child1"):
        pass
    with tracer.start_span("child2"):
        pass