fix(logging): parse DYN_LOG filter directives when deriving engine log level - #13326
fix(logging): parse DYN_LOG filter directives when deriving engine log level#13326azrabano23 wants to merge 5 commits into
Conversation
…g level configure_dynamo_logging() passed the raw DYN_LOG string to log_level_mapping(), which only exact-matched lowercase whole-string level names and mapped "trace" to INFO. As a result, documented filter forms such as DYN_LOG=debug,dynamo=debug, uppercase values such as DYN_LOG=DEBUG, and DYN_LOG=trace all silently degraded the engine (sglang) loggers to INFO. Factor the per-directive parsing already used by python_log_level_mapping() into a shared filter_level_mapping() helper: split the filter on commas, take the level after the last "=" in each directive, normalize case/whitespace, and use the lowest enabled level. log_level_mapping() now maps "trace" to DEBUG (Python has no TRACE level). The logging-config-file short-circuit in python_log_level_mapping() is preserved and intentionally not applied to the engine path. Extend test_vllm_logging.py with coverage for both mapping helpers and for the sglang logging config produced for directive-style, uppercase, trace, and default DYN_LOG values. Signed-off-by: Azra Bano <azrabano.work@gmail.com>
|
👋 Hi azrabano23! Thank you for contributing to ai-dynamo/dynamo. Just a reminder: The 🚀 |
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Enterprise Run ID: 📒 Files selected for processing (2)
Included review availability: Your plan includes up to 12 reviews per rolling hour; 11 remain after this review. WalkthroughChangesLogging filter mapping
Estimated code review effort: 3 (Moderate) | ~20 minutes Merge Risk: ⚪ Minimal · up to The change makes engine logging honor documented DYN_LOG directives while preserving existing behavior for unchanged inputs, with targeted tests and formatting checks reported as passing; no actionable merge-blocking risk remains. 🚥 Pre-merge checks | ✅ 3 | ❌ 2❌ Failed checks (2 warnings)
✅ Passed checks (3 passed)
✨ Finishing Touches 💡 1🛠️ Fix failing CI checks 💡
Comment |
|
Signed-off-by: Azra Bano <azrabano.work@gmail.com>
|
CI status: the Generated API References check flagged that this PR's new |
| """ | ||
| return min( | ||
| log_level_mapping(directive.rsplit("=", 1)[-1]) | ||
| for directive in filters.split(",") |
There was a problem hiding this comment.
Valid Rust env_filter target-only directives like DYN_LOG=dynamo_llm are treated as an unknown level and mapped to INFO, so DEBUG/TRACE engine logs can still be filtered out. Fix: recognize non-empty directives without = that are not bare level names as target-only TRACE-equivalent directives and map them to logging.DEBUG.
🤖 AI Fix
Update filter_level_mapping in lib/bindings/python/src/dynamo/runtime/logging.py to strip each comma-separated directive, skip empty directives, use the text after the final = when present, use log_level_mapping for recognized bare level tokens, and map any remaining non-empty target-only directive without = to logging.DEBUG; keep logging.INFO as the default when no directives remain.
There was a problem hiding this comment.
Agreed, that was a real gap: DYN_LOG=dynamo_llm is a valid env_filter directive meaning "target dynamo_llm at TRACE", but filter_level_mapping handed the whole token to log_level_mapping, which returned INFO for anything it did not recognise, so the engine loggers still dropped DEBUG.
Fixed in 7b7b3ca. filter_level_mapping now strips each comma-separated directive, skips empty ones, uses the text after the final = when present, maps recognised bare level names through log_level_mapping, and maps any other bare token to logging.DEBUG (Python has no TRACE). INFO remains the default when nothing is left. log_level_mapping is now a table lookup so the set of level names is defined once; that also adds off, which env_filter accepts and which previously would have become INFO (or DEBUG, once bare targets map to DEBUG) — it maps to CRITICAL, the most restrictive level configure_sglang_logging can name in its dictConfig.
Before/after on the old code: dynamo_llm -> INFO, dynamo_llm,warn -> INFO, off -> INFO; now DEBUG, DEBUG, CRITICAL.
Tests added to test_filter_level_mapping: dynamo_llm, dynamo_llm,warn, tokio=trace, Dynamo_LLM=Debug, WARN, off, error,off, "", " ", warn,,; and off in test_log_level_mapping.
python -m pytest components/src/dynamo/vllm/tests/test_vllm_logging.py # 48 passed
isort / black / flake8 (pre-commit args) / ruff 0.5.2 / codespell on the two files: clean
I ran the test file with a stub for dynamo._core.log_message since I do not have the compiled bindings locally; nothing in the file needs the extension beyond that import. The branch is merged with current main; the generated Python API pages are no longer committed since #13556, so there is nothing to regenerate for the docstring change.
Signed-off-by: Azra Bano <azrabano.work@gmail.com> # Conflicts: # docs/fern/pages/reference/api/python/README.mdx # docs/fern/pages/reference/api/python/runtime.mdx
…ping A Rust env_filter directive without a level, e.g. DYN_LOG=dynamo_llm, enables TRACE for that target. filter_level_mapping() fed the whole directive to log_level_mapping(), which did not recognize it and fell back to INFO, so the engine loggers still discarded DEBUG records that the user had asked for. Parse each directive as env_filter does: strip whitespace, skip empty entries, take the text after the final "=" when present, map bare level names (now including "off", which has no Python equivalent and maps to CRITICAL) and map any other bare token to DEBUG because it names a target at TRACE. INFO remains the default when nothing is left. Signed-off-by: Azra Bano <azrabano.work@gmail.com> Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Overview
configure_dynamo_logging()derives the level for the engine (sglang) loggers fromDYN_LOG, but passed the raw filter string tolog_level_mapping(), which only exact-matches lowercase whole-string level names and mapped"trace"to INFO. This PR factors the directive parsing already used bypython_log_level_mapping()into a sharedfilter_level_mapping()helper and uses it for the engine path.What was broken
Engine log level derived from
DYN_LOGbefore → after this change:DYN_LOGdebug,dynamo=debug(documented form, e.g. writing-unified-backends.md)DEBUGtracedebug!)dynamo_runtime=debugdebuginfowarn/error/criticalpython_log_level_mapping()now delegates to the shared helper; its behavior is unchanged for every input, including theDYN_LOGGING_CONFIG_PATH/ default-TOML short-circuit, which is intentionally not applied to the engine path (Rust merges TOML filters afterDYN_LOG, so preserving DEBUG there is only correct for the Python bridge level, not for engine logger config).Verification
components/src/dynamo/vllm/tests/test_vllm_logging.py: parametrized unit tests forlog_level_mapping(case/whitespace normalization, trace, unknown values) andfilter_level_mapping(bare, scoped, and mixed directives), plus end-to-end tests asserting the generated sglang logging config is DEBUG fordebug/DEBUG/trace/debug,dynamo=debugand INFO whenDYN_LOGis unset — the four DEBUG cases fail on main.ruff check,black --check, andisort --check-onlyclean on both files at the pre-commit pinned versions.Summary by CodeRabbit
Bug Fixes
DYN_LOGsettings.Tests