Skip to content

refactor(logging): use lazy %-style formatting in log calls - #1846

Merged
hassiebp merged 2 commits into
langfuse:mainfrom
DavidTraina:refactor/lazy-percent-style-logging
Aug 28, 2026
Merged

refactor(logging): use lazy %-style formatting in log calls#1846
hassiebp merged 2 commits into
langfuse:mainfrom
DavidTraina:refactor/lazy-percent-style-logging

Conversation

@DavidTraina

@DavidTraina DavidTraina commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

What does this PR do?

Converts all 124 f-string logging calls in langfuse/ to lazy %-style args, and enables ruff G004 so they stay that way.

f-strings are built before logger.debug(...) is called, so the message is assembled whether or not the level is enabled. The langfuse logger defaults to WARNING, so debug/info calls on tracing hot paths were building strings nobody reads.

Measured per call, logger at the default WARNING:

Site Frequency Before After
CallbackHandler.on_llm_new_token per streamed token 0.553 us 0.052 us
CallbackHandler._log_debug_event (15 call sites) per LangChain event 0.553 us 0.052 us
span_processor.on_start propagated attributes per span start under propagate_attributes() 0.52 us (3 attrs) / 0.94 us (8 attrs) 0.154 us
resource_manager.add_score_task / add_trace_task per score / trace update 0.218 us 0.077 us

For warning/error calls the effect depends on the configured level, since laziness only pays off when a call is suppressed: 1.85 us -> 2.07 us when the record is emitted (the default), and 0.088 us -> 0.049 us when the SDK is quieted to ERROR or above. They are converted anyway so the codebase has one style and G004 can be enabled with no exceptions.

Also adds G004 plus logger-objects to pyproject.toml, and documents the rule in AGENTS.md and code_review.md as the maintenance contract in AGENTS.md requires. ruff check . is clean repo-wide; tests/ and scripts/ had no violations to begin with.

Overlap with #1845

Both PRs touch the span_formatter debug call in on_end. This PR only makes it lazy, which does not remove the cost, because the argument is still evaluated eagerly. #1845 adds the isEnabledFor guard that does remove it. Whichever merges second needs a trivial rebase on that one call.

I also swept for other expensive arguments hidden behind a disabled level and found none. After this PR, seven debug/info calls in langfuse/ still pass a function call as an argument: span_formatter (the one #1845 guards, 28-167 us), _get_scope_name x3 (two attribute lookups), os.getpid() x2 on the fork path, and one dict.get(). Everything except span_formatter is well under a microsecond, and no value built with json.dumps/serialize/to_json/model_dump has a log call as its only consumer, so no further isEnabledFor guards are warranted.

Type of change

  • Bug fix
  • New feature
  • Breaking change
  • Refactor
  • Documentation update
  • Tooling, CI, or repo maintenance

Verification

uv run --frozen ruff check .                                  # All checks passed!
uv run --frozen mypy langfuse --no-error-summary              # exit 0
uv run --frozen pytest -n auto --dist worksteal tests/unit    # 686 passed, 2 skipped

The conversion was generated from the AST rather than by hand, and checked three ways:

  1. Each converted call reconstructed from its (format, args) pair back into canonical f-string form and compared against main: 124/124 identical, 0 mismatches.
  2. All 126 lazy calls rendered with dummy args: no malformed formats, no placeholder/argument count mismatches, no stray unescaped %.
  3. Suite re-run with the langfuse logger at DEBUG and a handler that fails on formatting errors, which logging normally swallows via handleError: 683 passed, 0 formatting errors.

Edge cases covered: literal % escaped to %%, {v:.1f} / {v:.2f} to %.1f / %.2f, f"{name=}" to name=%r, embedded newlines, mixed quoting, implicit concatenation. Original message line-splitting is preserved. The three # type: ignore comments in propagation.py are kept.

ruff format --check . flags tests/unit/test_media.py, but that drift pre-exists on main and is untouched here. CI's lint job runs ruff check ., which passes. e2e / live_provider were not run: no network, serialization, or control-flow behavior changes.

Checklist

  • I self-reviewed the diff using code_review.md.
  • I added or updated tests for behavior changes. -- no behavior change; message content verified identical to main at all 124 sites
  • I updated docs, examples, or .env.template if needed.
  • I did not hand-edit generated files; if generated files changed, I used the upstream regeneration path.
  • I did not commit secrets or credentials.

@claude claude Bot 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.

Claude Code Review

This pull request is from a fork — automated review is disabled. A repository maintainer can comment @claude review to run a one-time review.

@DavidTraina
DavidTraina force-pushed the refactor/lazy-percent-style-logging branch 2 times, most recently from 730f32a to 3787e9e Compare August 28, 2026 01:18
@DavidTraina
DavidTraina force-pushed the refactor/lazy-percent-style-logging branch from 3787e9e to 6bc62d3 Compare August 28, 2026 01:31
@hassiebp
hassiebp merged commit d22f833 into langfuse:main Aug 28, 2026
2 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants