Skip to content

fix(sdk): count logs dropped by the recursion guard - #5676

Open
RichardoMrMu wants to merge 10 commits into
open-telemetry:mainfrom
RichardoMrMu:fix/count-logs-dropped-by-recursion-guard
Open

RichardoMrMu wants to merge 10 commits into
open-telemetry:mainfrom
RichardoMrMu:fix/count-logs-dropped-by-recursion-guard

Conversation

@RichardoMrMu

Copy link
Copy Markdown

Description

SimpleLogRecordProcessor.on_emit discards a record when it detects a recursive emit loop
and logs that it is doing so, but does not record the drop on
otel.sdk.processor.log.processed. The already-shutdown early return nine lines below it
does record its drop, with error.type=already_shutdown:

if cnt > 3:
    _propagate_false_logger.warning(
        "SimpleLogRecordProcessor.on_emit has entered a recursive loop. Dropping log ..."
    )
    return                                    # <- dropped, not counted
token = attach(...)
try:
    if self._shutdown:
        _logger.warning("Processor is already shutdown, ignoring call")
        self._metrics.drop_items(1, "already_shutdown")   # <- dropped, counted
        return

Two discard paths in the same method, with the same self._metrics in hand, disagree about
whether a dropped record is worth counting.

Measured on main, driving a real recursion with an exporter that logs while exporting:

discard path records dropped recorded on the counter
recursion guard 1 0 — counter reads {'<none>': 4}
already shutdown 1 1 — counter reads {'already_shutdown': 1}

A consumer summing otel.sdk.processor.log.processed therefore cannot tell that a record
was lost, even though the SDK knew it was dropping one and already has the vocabulary to
say so.

Why this touches _processor_metrics.py too

drop_items selects between prebuilt attribute dicts rather than building them from its
argument:

def drop_items(self, count: int, error_type: str = "queue_full") -> None:
    if error_type == "already_shutdown":
        self._processed.add(count, self._already_shutdown_attrs)
    else:
        self._processed.add(count, self._dropped_attrs)

So adding the call alone would silently attribute a recursion drop to
error.type=queue_full, which would be worse than not counting it. The change adds one
prebuilt dict and one branch, mirroring the existing already_shutdown shape; there is no
signature or public API change, and NoOpProcessorMetrics is unaffected.

History

The recursion guard came from #4799 (merged 2025-12) and the processor accounting from
#5472 (merged 2026-08). #5472's diff on this file begins after the try: — it moved
finish_items and reworked error handling — so the guard above it was never in scope for
that work. This fills that gap rather than revisiting a decision.

Tests

test_metrics_recursive_loop in opentelemetry-sdk/tests/logs/test_export.py, placed
beside test_simple_log_record_processor_doesnt_enter_recursive_loop whose gap it fills.
It is the intersection of two tests this suite already has: the recursion trigger from that
test, and the counter assertions from test_metrics_already_shutdown.

  • On main it fails with 0 != 1 : the log dropped by the recursion guard was not counted.
  • With this change it passes.
  • The whole of test_export.py passes: 25 passed.

Type of change

  • Bug fix (non-breaking change which fixes an issue)

Does This PR Require a Core Repo Change?

  • Yes.
  • No.

@RichardoMrMu
RichardoMrMu requested a review from a team as a code owner September 20, 2026 09:46
@linux-foundation-easycla

linux-foundation-easycla Bot commented Sep 20, 2026 •

Copy link
Copy Markdown

CLA Signed
The committers listed above are authorized under a signed CLA.

  • ✅ login: RichardoMrMu / name: RichardoMu (f4f222f)

@opentelemetry-pr-dashboard

opentelemetry-pr-dashboard Bot commented Sep 20, 2026 •

Copy link
Copy Markdown

Pull request dashboard status

Waiting on the author · refreshed 2026-09-27 05:48 UTC

Respond to 1 review item (e.g. link a commit, explain why not, ask a follow-up):

  • Top-level threads: 1
Status above doesn't look right?
  • Just replied or pushed? Anything around or after the refresh time above may not be picked up yet — give it a few minutes.
  • Should this be with reviewers? Comment /dashboard route:reviewers to route it to them.
  • Anything wrong — including the routing? Report it with what you expected; it helps us improve the dashboard.

SimpleLogRecordProcessor.on_emit discards a record when it detects a
recursive emit loop, and says so in the log, but does not record the drop
on otel.sdk.processor.log.processed. The already-shutdown early return nine
lines below it does, with error.type=already_shutdown, so the two discard
paths in the same method disagree about whether a dropped record is worth
counting.

Measured on main, driving a real recursion with an exporter that logs while
exporting:

  recursion drop:  {'<none>': 4}            -- 1 record dropped, 0 counted
  shutdown drop:   {'already_shutdown': 1}  -- 1 record dropped, 1 counted

So the counter under-reports: a consumer summing otel.sdk.processor.log
.processed cannot tell that a record was lost, even though the SDK knew it
was dropping one.

Note that drop_items selects between prebuilt attribute dicts rather than
building them from its argument, so passing a new error_type without adding
the matching dict would silently attribute the drop to error.type=queue_full.
Hence the small change to _processor_metrics.py alongside it.

The recursion guard was added in open-telemetry#4799 (merged 2025-12) and the processor
accounting in open-telemetry#5472 (merged 2026-08); open-telemetry#5472's diff on this file starts after
the try: block, so this path was simply never reached by that work.

Assisted-by: Doubao
@RichardoMrMu
RichardoMrMu force-pushed the fix/count-logs-dropped-by-recursion-guard branch from 87f5dbe to f4f222f Compare September 20, 2026 09:49
@github-project-automation github-project-automation Bot moved this to Approved PRs in Python PR digest Sep 21, 2026

@herin049 herin049 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.

Reminder to run pre-commit to fix the failing formatting checks in CI.

Comment thread .changelog/5676.fixed Outdated
@@ -0,0 +1 @@
Count logs dropped by `SimpleLogRecordProcessor`'s recursion guard on `otel.sdk.processor.log.processed` with `error.type=recursion`

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.

Please include the package name (i.e. opentelemetry-sdk) in the changelog fragment.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Added the package name -- the fragment now reads `opentelemetry-sdk`: count logs dropped by ..., matching the house style (e.g. #5660/#5680). Updated in the latest commit.

This branch has not been deployed

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

Labels

None yet

Projects

Status: Reviewed PRs that need fixes

Development

Successfully merging this pull request may close these issues.

3 participants