Skip to content

Python: record gen_ai.client.operation.duration for failed chat and embedding calls - #7819

Open
Venkat Ramachandran (venkat-uk) wants to merge 1 commit into
microsoft:mainfrom
venkat-uk:fix/otel-duration-metric-on-error
Open

Python: record gen_ai.client.operation.duration for failed chat and embedding calls#7819
Venkat Ramachandran (venkat-uk) wants to merge 1 commit into
microsoft:mainfrom
venkat-uk:fix/otel-duration-metric-on-error

Conversation

@venkat-uk

Copy link
Copy Markdown

Motivation & Context

gen_ai.client.operation.duration is only recorded when a call succeeds. Every failed
chat call and every failed embedding call is missing from the metric.

The OpenTelemetry GenAI semantic conventions define this metric for failed operations too,
with error.type set to the class of the error. error.type is listed as conditionally
required, "if the operation ended in an error".

The framework already knows this. _capture_response in
python/packages/core/agent_framework/observability.py has a branch that copies
error.type from the attribute dictionary into the metric attributes:

if operation_duration_histogram and duration is not None:
    if OtelAttr.ERROR_TYPE in attributes:
        attrs[OtelAttr.ERROR_TYPE] = attributes[OtelAttr.ERROR_TYPE]
    operation_duration_histogram.record(duration, attributes=attrs)

No caller ever puts OtelAttr.ERROR_TYPE into that dictionary, and _capture_response is
only reached on the success path, so the branch is unreachable in production. The only
place that covers it is test_capture_response_with_error_type, which calls the helper
directly.

FunctionTool.invoke in _tools.py already does this correctly. It sets
attributes[OtelAttr.ERROR_TYPE] in its except block and records the duration histogram
in a finally block, so failed tool calls do reach
agent_framework.function.invocation.duration. The chat and embedding layers do not.

What this costs an operator: a dashboard built on gen_ai.client.operation.duration shows
only healthy traffic. A provider outage that makes every call time out after 30 seconds
looks like a drop in request volume, not a latency or error problem. There is no error rate
to alert on, because no error series exists.

Description & Review Guide

  • What are the major changes?

    A new helper, _capture_operation_error, records the duration histogram for a failed
    call. It filters the request attributes through GEN_AI_METRIC_ATTRIBUTES, the same
    filter _capture_response uses on the success path, then adds
    error.type = type(exception).__name__.

    It is called from three failure paths:

    1. ChatTelemetryLayer, streaming, when the underlying client raises while the stream is
      being set up.
    2. ChatTelemetryLayer, streaming, when the stream raises during iteration. The duration
      comes from duration_state, which the existing _record_duration cleanup hook fills
      in on both success and failure.
    3. ChatTelemetryLayer, non-streaming, and EmbeddingTelemetryLayer.
  • What is the impact of these changes?

    The metric now has a series for failed calls. Nothing that is recorded today changes:
    the success path, span attributes, the token usage histogram, and the exception recorded
    on the span are all untouched. No public API changes. No signature changes.

    AgentTelemetryLayer is deliberately left alone. It calls _capture_response without a
    histogram, so it does not emit this metric at all today, on success or on failure.
    Making it emit one would be a new feature rather than a fix.

  • What do you want reviewers to focus on?

    Two things. First, whether EmbeddingTelemetryLayer should be in the same PR. It shares
    the metric and the same gap, so I included it, but it is proved only by the helper's unit
    test and by the existing openai embedding tests staying green, not by a new end-to-end
    embedding test. Second, whether the mid-stream case should record a duration when
    duration_state is empty. Today it records nothing in that case, which I kept, because a
    zero would be wrong.

How tested

The two chat tests were written first and fail on d9d3fb6 with:

AssertionError: Expected 'record' to have been called once. Called 0 times.

Four tests added to packages/core/tests/core/test_observability.py:

Test Covers
test_capture_operation_error_keeps_only_metric_attributes gen_ai.conversation.id is dropped, error.type is added
test_capture_operation_error_without_histogram_or_duration no histogram or no duration records nothing
test_chat_client_records_duration_on_error non-streaming failure records once with error.type
test_chat_client_records_duration_on_streaming_error mid-stream failure records once with error.type

Commands run from python/:

uv run poe test -A -m "not integration"
9628 passed, 35 skipped, 2 xfailed in 40.11s

uv run poe test -P core
4205 passed, 21 skipped, 2 xfailed in 14.67s

uv run poe test -P openai
452 passed in 5.73s

uv run poe test -P anthropic
154 passed in 4.42s

uv run poe test-typing -P core
mypy, pyright, pyrefly, ty, zuban: all 5 passed

uv run ruff format --check <the two changed files>    # already formatted
uv run ruff check <the two changed files>             # all checks passed
uv run bandit -c pyproject.toml <the two changed files>   # 0 issues

uv run poe pyright -P core reports 16 errors on observability.py and _workflows/_viz.py.
All 16 are missing optional imports (opentelemetry.exporter.otlp.proto.grpc.*, graphviz)
and all 16 reproduce on a clean checkout of d9d3fb6 with the same environment. None of them
are on changed lines.

The openai embedding suite caught a real problem in the first version of this change:
OpenAIEmbeddingClient does not always have duration_histogram set. The embedding call
site now uses getattr(self, "duration_histogram", None), which is what the chat layer
already does.

Tradeoffs

  • Every failed call now writes one histogram point that was not written before. On an
    estimate of one failure in a thousand calls this is a rounding error. On a provider
    outage it is one point per failed call, the same rate the success path already writes.
  • error.type is the exception class name. On a wrapper exception that is the wrapper's
    name, not the underlying provider status code. This matches how capture_exception
    already labels the span, so the metric and the trace agree with each other.
  • Anyone whose alerting counts series on gen_ai.client.operation.duration will see a new
    set of series appear, one per distinct exception class. The cardinality is bounded by the
    number of exception types, and the attribute set is otherwise the same filtered set the
    success path uses.
  • I did not add an end-to-end embedding test. The embedding layer change is covered by the
    helper's unit test and by the existing openai and anthropic suites staying green.

Related Issue

Fixes #7818

Contribution Checklist

  • The code builds clean without any errors or warnings
  • All unit tests pass, and I have added new tests where possible
  • The PR follows the Contribution Guidelines
  • This PR is linked to an issue and there is no other open PR for this issue (see Related Issue above).
  • This is not a breaking change.

The GenAI semantic conventions define gen_ai.client.operation.duration for failed
operations as well as successful ones, with error.type set to the class of the
error. ChatTelemetryLayer and EmbeddingTelemetryLayer only recorded the histogram
on the success path, so error latency never reached the metric and the metric
carried no error rate.

_capture_response already had the branch that copies error.type into the metric
attributes, but no caller ever put error.type into the attribute dict, so that
branch was unreachable in production. Add _capture_operation_error and call it
from the three chat and embedding failure paths: the streaming setup failure, the
mid-stream failure, and the non-streaming failure.

The metric attribute set is filtered through GEN_AI_METRIC_ATTRIBUTES, the same
filter the success path uses, so no high-cardinality attribute reaches the metric.

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Records failed chat and embedding operation durations with OpenTelemetry error attributes.

Changes:

  • Adds _capture_operation_error.
  • Instruments chat and embedding failure paths.
  • Adds helper and chat failure tests.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 2 comments.

File Description
python/packages/core/agent_framework/observability.py Records duration metrics for failed operations.
python/packages/core/tests/core/test_observability.py Tests error metric filtering and chat failures.

💡 Add a code-review agent skill for context-aware, tailored reviews. Learn more in the docs.

Comment on lines +1922 to +1927
_capture_operation_error(
attributes=attributes,
exception=exception,
operation_duration_histogram=getattr(self, "duration_histogram", None),
duration=perf_counter() - start_time_stamp,
)
Comment on lines +1712 to +1717
_capture_operation_error(
attributes=attributes,
exception=exception,
operation_duration_histogram=getattr(self, "duration_histogram", None),
duration=perf_counter() - start_time,
)
@venkat-uk

Copy link
Copy Markdown
Author

@microsoft-github-policy-service agree

@venkat-uk

Copy link
Copy Markdown
Author

I have sole ownership of the intellectual property rights to my Submissions and I am not making Submissions in the course of work for my employer

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

python Usage: [Issues, PRs], Target: Python

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Python: gen_ai.client.operation.duration is never recorded for failed chat or embedding calls

2 participants