Skip to content

fix(sdk): respect timeout_millis in BatchProcessor.force_flush - #5842

Open
Dotify71 wants to merge 5 commits into
open-telemetry:mainfrom
Dotify71:fix-batch-processor-force-flush-timeout
Open

Dotify71 wants to merge 5 commits into
open-telemetry:mainfrom
Dotify71:fix-batch-processor-force-flush-timeout

Conversation

@Dotify71

@Dotify71 Dotify71 commented Oct 27, 2026 •

Copy link
Copy Markdown
Contributor

Description

Refs #4568
Part of #5684

In BatchProcessor (opentelemetry-sdk/src/opentelemetry/sdk/_shared_internal/__init__.py), force_flush(timeout_millis) previously accepted a timeout_millis argument but never used it, blocking indefinitely until all telemetry was exported regardless of the specified deadline:

# TODO: Fix force flush so the timeout is used https://github.com/open-telemetry/opentelemetry-python/issues/4568.
def force_flush(self, timeout_millis: int | None = None) -> bool:
    if self._shutdown:
        return False
    # Blocking call to export.
    self._export(BatchExportStrategy.EXPORT_ALL)
    return True

Changes Made

  1. Timed Lock Wait & Deadline Check in _export:
    • Added deadline: float = math.inf to _export().
    • Acquires _export_lock with timeout=remaining when deadline is finite (remaining = deadline - time.time()), returning False immediately if the deadline has already passed (remaining <= 0) or if lock acquisition times out.
    • Guarded against OverflowError on math.inf and negative timeout values for threading.Lock.acquire().
    • Checks if time.time() >= deadline: at each batch iteration, returning False if the deadline is exceeded before all batches are exported, and True if all batches were successfully drained.
  2. Compute Deadline in force_flush:
    • Computes deadline = time.time() + (timeout_millis / 1000) if timeout_millis is not None else math.inf.
    • Returns the result of self._export(BatchExportStrategy.EXPORT_ALL, deadline).
  3. Tests & Changelog:
    • Added unit tests in test_batch_processor.py covering:
      • test_force_flush_returns_true_when_all_exported
      • test_force_flush_returns_false_when_timeout_exceeded (tested with patched time.time)
      • test_force_flush_returns_false_when_lock_acquisition_times_out
      • test_force_flush_returns_false_when_shutdown
    • Added changelog entry in .changelog/5842.fixed.

Type of change

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

How Has This Been Tested?

  • Ran pytest opentelemetry-sdk/tests/shared_internal/test_batch_processor.py -v (all 29 tests passed).
  • Ran pytest opentelemetry-sdk/tests/trace/export/test_export.py opentelemetry-sdk/tests/logs/test_export.py -v (all 44 tests passed).
  • Ran ruff format --check opentelemetry-sdk and ruff check opentelemetry-sdk.

Checklist:

  • Followed the style guidelines of this project
  • Changelogs have been updated
  • Unit tests have been added
  • Documentation has been updated

@Dotify71
Dotify71 requested a review from a team as a code owner October 27, 2026 06:33
@opentelemetry-pr-dashboard

opentelemetry-pr-dashboard Bot commented Oct 27, 2026 •

Copy link
Copy Markdown

Pull request dashboard status

Waiting on the author · refreshed 2026-11-03 17:31 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.

@chrikrah chrikrah left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

@Dotify71 blocking: the title says force_flush respects timeout_millis, but the loop checks the deadline only after it holds _export_lock. While the worker drains a slow exporter, force_flush(100) waits 2.95s past its deadline.

A timed lock wait fixes that, with a guard: deadline defaults to math.inf, and a lapsed one goes negative. One slow export still overruns until export takes a timeout. That is the ask in #4568, and Refs #4568 fits better than Fixes.

# git archive 2c489c0, Python 3.12, opentelemetry.sdk from the exported tree
$ python -m pytest opentelemetry-sdk/tests/shared_internal/test_batch_processor.py -q -p no:cacheprovider
27 passed, 2 warnings in 7.46s
# _shared_internal/__init__.py from base 7fd5f6b, tests kept
2 failed, 25 passed  (test_force_flush_returns_false_when_timeout_exceeded, both processors)

# 0.5s exporter, max_export_batch_size=1, 6 spans ended, then force_flush(timeout_millis=100)
$ python -I lockwait.py
force_flush(100) -> True after 2.95s     # head, queue already drained by the worker
force_flush(100) -> False after 0.10s    # lock acquired with the remaining time, finite deadline
# that variant fails the new timeout test: its time.time side_effect holds two values

# Python 3.12.3, threading.Lock().acquire(timeout=...)
timeout=math.inf -> OverflowError timestamp out of range for platform time_t
timeout=-0.01    -> ValueError timeout value must be positive
# not run: tox lint, the OTLP exporters

Want the probe as a test here?

@github-project-automation github-project-automation Bot moved this to Reviewed PRs that need fixes in Python PR digest Oct 29, 2026
@Dotify71

Copy link
Copy Markdown
Contributor Author

@Dotify71 blocking: the title says force_flush respects timeout_millis, but the loop checks the deadline only after it holds _export_lock. While the worker drains a slow exporter, force_flush(100) waits 2.95s past its deadline.

A timed lock wait fixes that, with a guard: deadline defaults to math.inf, and a lapsed one goes negative. One slow export still overruns until export takes a timeout. That is the ask in #4568, and Refs #4568 fits better than Fixes.

# git archive 2c489c0, Python 3.12, opentelemetry.sdk from the exported tree
$ python -m pytest opentelemetry-sdk/tests/shared_internal/test_batch_processor.py -q -p no:cacheprovider
27 passed, 2 warnings in 7.46s
# _shared_internal/__init__.py from base 7fd5f6b, tests kept
2 failed, 25 passed  (test_force_flush_returns_false_when_timeout_exceeded, both processors)

# 0.5s exporter, max_export_batch_size=1, 6 spans ended, then force_flush(timeout_millis=100)
$ python -I lockwait.py
force_flush(100) -> True after 2.95s     # head, queue already drained by the worker
force_flush(100) -> False after 0.10s    # lock acquired with the remaining time, finite deadline
# that variant fails the new timeout test: its time.time side_effect holds two values

# Python 3.12.3, threading.Lock().acquire(timeout=...)
timeout=math.inf -> OverflowError timestamp out of range for platform time_t
timeout=-0.01    -> ValueError timeout value must be positive
# not run: tox lint, the OTLP exporters

Want the probe as a test here?

Yes, please adding the probe as a test here would be fantastic.
I'm updating _export to use a timed lock wait on _export_lock (handling finite remaining <= 0 and math.inf cases so we don't block past the deadline or hit OverflowError/ValueError), and updating the description to Refs #4568.

Please feel free to share the test probe or push/suggest it, and I'll include it in the branch :))

- Acquire _export_lock with timeout=remaining when deadline is finite
- Guard against negative timeout values and math.inf OverflowError
- Add test_force_flush_returns_false_when_lock_acquisition_times_out
@Dotify71
Dotify71 requested a review from chrikrah October 29, 2026 11:36

@chrikrah chrikrah left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

@Dotify71 the timed lock wait fixes my blocker at 58c2682, and your lock-holder test is the probe I offered, so mine isn't needed. From my perspective this can be merged.

# git archive 58c2682, Python 3.12.3, opentelemetry.sdk imported from the export
$ python -m pytest opentelemetry-sdk/tests/shared_internal/test_batch_processor.py -q -p no:cacheprovider
29 passed, 2 warnings
# _shared_internal/__init__.py from 2c489c0, my last review's head, tests kept
2 failed, 27 passed   # test_force_flush_returns_false_when_lock_acquisition_times_out, both processors

$ python -I lockwait.py   # 0.5s exporter, max_export_batch_size=1, 6 spans, then force_flush
force_flush(100) -> False after 0.10s   # 58c2682 (2c489c0: True after 2.95s)
force_flush()    -> True after 2.85s    # no timeout, math.inf path
_export(EXPORT_ALL, deadline=now - 1) -> False
# not run: tox lint, the OTLP exporters

An export already in flight still runs past the deadline, which Refs #4568 covers, and the math.inf default is what herin049 suggested on #4982. Could the description list the lock-acquisition test too? It still says 27 passed.

@Dotify71

Dotify71 commented Nov 2, 2026

Copy link
Copy Markdown
Contributor Author

@Dotify71 the timed lock wait fixes my blocker at 58c2682, and your lock-holder test is the probe I offered, so mine isn't needed. From my perspective this can be merged.

# git archive 58c2682, Python 3.12.3, opentelemetry.sdk imported from the export
$ python -m pytest opentelemetry-sdk/tests/shared_internal/test_batch_processor.py -q -p no:cacheprovider
29 passed, 2 warnings
# _shared_internal/__init__.py from 2c489c0, my last review's head, tests kept
2 failed, 27 passed   # test_force_flush_returns_false_when_lock_acquisition_times_out, both processors

$ python -I lockwait.py   # 0.5s exporter, max_export_batch_size=1, 6 spans, then force_flush
force_flush(100) -> False after 0.10s   # 58c2682 (2c489c0: True after 2.95s)
force_flush()    -> True after 2.85s    # no timeout, math.inf path
_export(EXPORT_ALL, deadline=now - 1) -> False
# not run: tox lint, the OTLP exporters

An export already in flight still runs past the deadline, which Refs #4568 covers, and the math.inf default is what herin049 suggested on #4982. Could the description list the lock-acquisition test too? It still says 27 passed.

Thanks for the thorough review and testing, @chrikrah I've updated the description to list test_force_flush_returns_false_when_lock_acquisition_times_out and updated the test count to 29 passed.

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.

2 participants