Skip to content

perf: format local evaluation debug logs lazily - #81

Merged
sandeep-madugula merged 3 commits into
amplitude:mainfrom
yienyien:perf-lazy-evaluate-debug-log
Nov 10, 2026
Merged

sandeep-madugula merged 3 commits into
amplitude:mainfrom
yienyien:perf-lazy-evaluate-debug-log

Conversation

@yienyien

@yienyien yienyien commented Oct 7, 2026 •

Copy link
Copy Markdown
Contributor

Summary

LocalEvaluationClient.evaluate_v2 logs the whole flag config snapshot at DEBUG on every call:

# local/client.py
self.logger.debug(f"[Experiment] Evaluate: user={user} - Flags: {flag_configs}")

The f-string is built before the logger checks its level, so every evaluation renders every flag config to text, even when only one flag is requested and even when DEBUG is disabled. DEBUG is disabled by default: LocalEvaluationConfig sets the default logger to WARNING unless debug=True. The cost therefore grows with the number of flags in the project, not with the number of flags evaluated, and it is paid on the hot path of every server-side evaluation for a log line that is then thrown away.

Observed impact

Measured on this branch's base (main, 1.13.0) with 100 synthetic flags (two segments each, one condition, one bucket) in storage, evaluating a single flag with the default logger (WARNING), best of 5 × 5,000 calls on Python 3.14:

evaluate_v2(user, {'flag-7'})
main 0.383 ms
this PR 0.005 ms

About 99% of the evaluation time went into building a log message that was then discarded. We found this in production, where the repr was the largest cost of local evaluation in our request handlers. We currently work around it by swapping the storage's snapshot for a dict subclass with a constant-time __repr__. We would like to drop that workaround.

Change

The two logger.debug calls in evaluate_v2 now use the standard logging lazy formatting ("... %s", arg) instead of f-strings, so the arguments are only rendered when a handler actually emits the record. With DEBUG enabled, the output is identical: %s and an f-string placeholder both call str().

self.logger.debug("[Experiment] Evaluate: user=%s - Flags: %s", user, flag_configs)
...
self.logger.debug("[Experiment] Evaluate Result: %s", variants)

The other f-string debug calls in the SDK (flag_config_updater, cohort_download_api, remote/client) run once per poll or per network fetch, not per evaluation, so this PR leaves them as they are to keep the diff minimal. Happy to convert them too if you prefer one style throughout.

Tests (tests/local/evaluate_logging_test.py, no network, client never started):

  • with the logger at WARNING, evaluate_v2 evaluates correctly without rendering any flag config (EvaluationFlag.__repr__ patched to raise). This test fails on main.
  • with the logger at DEBUG, both records are still emitted with the same content (user JSON, every flag config, result).

The 4 setUpClass errors in tests/local/client_test.py and tests/local/client_eu_test.py (KeyError: 'API_KEY' / 'EU_API_KEY') occur identically on unmodified main in my environment. They need the CI secrets.

Checklist

  • Does your PR title have the correct title format?
  • Does your PR have a breaking change?: no. Log messages are unchanged when DEBUG is enabled.

🤖 Generated with Claude Code


Note

Low Risk
Behavior change is limited to when log strings are formatted; DEBUG output is unchanged, and new unit tests cover the logging path.

Overview
Local evaluation hot path no longer builds DEBUG log strings on every evaluate_v2 call. The two logger.debug lines in local/client.py switch from f-strings to lazy %s formatting so flag configs and results are only rendered when DEBUG is actually enabled—addressing large per-request cost when the default logger level is WARNING.

Tests in tests/local/evaluate_logging_test.py assert evaluation still works without rendering flag configs when DEBUG is off (via a patched EvaluationFlag.__repr__) and that DEBUG output still includes user, flags, and results when enabled.

CI pins the unit test workflow to ubuntu-22.04 instead of ubuntu-latest.

Reviewed by Cursor Bugbot for commit dfdd86b. Bugbot is set up for automated code reviews on this repo. Configure here.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@yienyien

yienyien commented Oct 7, 2026

Copy link
Copy Markdown
Contributor Author

This is a real pain point for us at WeWard, with a significant performance impact. We patched it locally and saw immediate benefits.

@yienyien
yienyien marked this pull request as ready for review October 12, 2026 14:51
@yienyien
yienyien requested a review from a team as a code owner October 12, 2026 14:51

@sandeep-madugula sandeep-madugula 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.

Reviewed with Codex. No blocking code findings: deferred logging formatting removes the expensive flag-config representation from the disabled-DEBUG evaluation path, and both enabled and disabled DEBUG behavior are covered by the added tests. The disabled-DEBUG regression test also fails against the original implementation as expected.

Updated the branch from main and fixed an existing CI runner incompatibility by pinning the unit-test runner to Ubuntu 22.04; Ubuntu 26.04 does not provide Python 3.8.

Full validation passed on Python 3.8, 3.12, and 3.14: each job ran 210 tests, with 4 existing skips. Run: https://github.com/amplitude/experiment-python-server/actions/runs/42886326835

That run used temporary maintainer branch ci/validate-python-pr-81-20261110 (73ee6b9), based on PR head dfdd86b. The source and tests are identical to the PR; the only additional difference enables the workflow on the temporary branch. The fork PR workflow has empty API_KEY/SECRET_KEY/EU_API_KEY/EU_SECRET_KEY values and consequently fails the seven cohort integration tests; those same tests pass in the maintainer run with the existing Unit Test environment secrets.

@sandeep-madugula
sandeep-madugula merged commit 19eaab7 into amplitude:main Nov 10, 2026
3 of 6 checks passed

This branch was successfully deployed

No deployments
Unit Test — dfdd86b4 Deployed Nov 10, 2026 by sandeep-madugula via test (3.14) #234
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