Skip to content

fix(platform): initialize logging before config resolution#892

Open
svvarom wants to merge 1 commit into
mainfrom
structured-startup-logs/smuley
Open

fix(platform): initialize logging before config resolution#892
svvarom wants to merge 1 commit into
mainfrom
structured-startup-logs/smuley

Conversation

@svvarom

@svvarom svvarom commented Jul 24, 2026

Copy link
Copy Markdown
Contributor

Problem

Piping platform logs to jq fails. Startup emits plain text before JSON logging is configured:

Warning: binding to 0.0.0.0 makes the service reachable on all network interfaces.
Docker is not available, setting runtime to NONE
{"level": "info", ... "[STARTUP] observability_init: 169ms"}

Two separate causes:

  1. run_platform() resolved configuration before calling initialize_obs(). Anything logged in that window has no handler on the root logger, so Python falls back to logging.lastResort — bare text on stderr, and everything below WARNING silently dropped. [STARTUP] resolve_config was being lost this way.
  2. The bind warning is a typer.echo, not a log record at all.

The format could not be known earlier because the chart only set config.service.log_format: json in the mounted config file — and reading that file is exactly what logs.

Changes

  • run.py — move initialize_obs() ahead of config resolution. Re-initialize logging afterward only if the config file disagrees with the environment (local / CLI use).
  • values.yaml — set LOG_FORMAT: "json" under the existing telemetry: env passthrough. Both OTELSettings and CommonServiceConfig read the bare LOG_FORMAT, so logging can be configured with no config file. No template changes; the existing nemo-common.otel-env helper already feeds both deployments.
  • cli.py — gate the bind warning on sys.stderr.isatty(). In a pod, binding to 0.0.0.0 is the intended configuration.

Verification

  • Live startup log: 0 non-JSON lines. [STARTUP] resolve_config now appears instead of being dropped.
  • helm template renders LOG_FORMAT into both the api and core-controller deployments.
  • nmp_platform_runner 112 passed, test_common_config.py + test_otel.py 45 passed. New test asserts initialize_obs runs before resolve_run_configuration.
  • Bind warning verified both ways: emitted on a pty, silent on a pipe.
  • ruff check / ruff format clean.

Not included

Docker is not available still logs twice, now as two JSON lines. Separate cause: global_settings_to_service_config constructs the config model twice (once for defaults + env, once with file values merged), and Pydantic runs validate_runtime on each. Both constructions are load-bearing. Left for a follow-up.

The vendored SDK copy of cli.py still has the ungated warning; it picks up the change on the next make update-sdk.

Summary by CodeRabbit

Release Notes

  • New Features

    • Log format can now be configured via environment variable across all services, enabling JSON output control without code changes.
  • Bug Fixes

    • Binding warnings now display only in interactive terminal sessions, reducing unnecessary noise in container deployments.
    • Improved logging initialization sequencing to ensure configuration consistency.

run_platform() resolved configuration before calling initialize_obs(), so
anything logged during config loading fell back to Python's logging.lastResort
handler: bare text on stderr, with everything below WARNING dropped. That put
unparseable lines into the JSON log stream.

Move observability init ahead of config resolution, and set LOG_FORMAT as an
env var in the chart so the format is known without reading the config file.
Also gate the interactive bind warning on a TTY check.

Signed-off-by: Swarom Muley <smuley@nvidia.com>
@svvarom
svvarom requested review from a team as code owners July 24, 2026 18:47
@github-actions github-actions Bot added the fix label Jul 24, 2026
@coderabbitai

coderabbitai Bot commented Jul 24, 2026

Copy link
Copy Markdown
Contributor

Review Change Stack

📝 Walkthrough

Walkthrough

Startup observability now initializes before configuration resolution, resolved logging settings are reapplied, Helm sets JSON logs, and bind-all warnings are limited to interactive terminals.

Changes

Observability and operational logging

Layer / File(s) Summary
Runner observability initialization and logging synchronization
packages/nmp_platform_runner/src/nmp/platform_runner/run.py, packages/nmp_platform_runner/tests/test_run.py
run_platform initializes observability before resolving configuration, reapplies differing log settings, and tests the startup call order.
Helm telemetry log-format override
k8s/helm/values.yaml
Telemetry environment overrides set LOG_FORMAT to json.
TTY-gated bind warning
packages/nemo_platform_ext/src/nemo_platform_ext/cli/commands/services/cli.py
Wildcard-bind warnings now require an interactive stderr terminal.

Sequence Diagram(s)

sequenceDiagram
  participant run_platform
  participant Observability
  participant Configuration
  participant StructuredLogging
  run_platform->>Observability: initialize_obs and setup_global_instrumentations
  run_platform->>Configuration: resolve_run_configuration and apply_run_environment
  run_platform->>StructuredLogging: initialize_logging when resolved settings differ
Loading

Suggested reviewers: ironcommit, tylersbray

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed Title clearly matches the main change: initializing logging before config resolution.
Docstring Coverage ✅ Passed No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
✨ Finishing Touches
📝 Generate docstrings
  • Create stacked PR
  • Commit on current branch
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch structured-startup-logs/smuley

Comment @coderabbitai help to get the list of available commands.

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

Actionable comments posted: 1

🧹 Nitpick comments (1)
packages/nmp_platform_runner/tests/test_run.py (1)

99-142: 🎯 Functional Correctness | 🔵 Trivial | ⚡ Quick win

Cover the reinitialization path and complete startup ordering.

This test only records initialize_obs and resolve_run_configuration, so it would pass even if setup_global_instrumentations ran first or the new initialize_logging() branch regressed. Add a case with differing environment/config log settings and assert reinitialization occurs before the resolve_config phase marker.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@packages/nmp_platform_runner/tests/test_run.py` around lines 99 - 142, The
test around run_platform must cover logging reinitialization and the complete
startup order, not only initialize_obs versus resolve_run_configuration. Extend
test_run_platform_initializes_logging_before_resolving_config to use differing
environment/config logging settings, record initialize_logging,
setup_global_instrumentations, and the resolve_config phase, then assert
reinitialization occurs before resolve_run_configuration and the
config-resolution marker, while preserving the existing initialization-order
assertion.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@packages/nmp_platform_runner/src/nmp/platform_runner/run.py`:
- Around line 97-108: Move _startup_phase("resolve_config", t0) in the run
configuration flow to after the service_config comparison and any
initialize_logging() call, while preserving the existing timing start and
logging reinitialization behavior.

---

Nitpick comments:
In `@packages/nmp_platform_runner/tests/test_run.py`:
- Around line 99-142: The test around run_platform must cover logging
reinitialization and the complete startup order, not only initialize_obs versus
resolve_run_configuration. Extend
test_run_platform_initializes_logging_before_resolving_config to use differing
environment/config logging settings, record initialize_logging,
setup_global_instrumentations, and the resolve_config phase, then assert
reinitialization occurs before resolve_run_configuration and the
config-resolution marker, while preserving the existing initialization-order
assertion.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Enterprise

Run ID: 50896d29-ef07-41d8-8719-71c13093ef9a

📥 Commits

Reviewing files that changed from the base of the PR and between 28e33c8 and 4ec8a83.

📒 Files selected for processing (4)
  • k8s/helm/values.yaml
  • packages/nemo_platform_ext/src/nemo_platform_ext/cli/commands/services/cli.py
  • packages/nmp_platform_runner/src/nmp/platform_runner/run.py
  • packages/nmp_platform_runner/tests/test_run.py

Comment on lines 97 to +108
t0 = time.perf_counter()
resolved = resolve_run_configuration(config)
apply_run_environment(resolved)
_startup_phase("resolve_config", t0)

# The config file may still override the environment (local / CLI use), so re-initialize
# logging when it disagrees with what the environment already configured.
service_config = get_common_service_config()
if otel_settings.log_format != service_config.log_format:
if (otel_settings.log_format, otel_settings.log_level) != (service_config.log_format, service_config.log_level):
otel_settings.log_format = service_config.log_format
if otel_settings.log_level != service_config.log_level:
otel_settings.log_level = service_config.log_level

t0 = time.perf_counter()
initialize_obs(resource_attributes=get_platform_resource_attributes())
setup_global_instrumentations()
_startup_phase("observability_init", t0)
initialize_logging()

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.

🎯 Functional Correctness | 🟠 Major | ⚡ Quick win

Reinitialize logging before recording the resolve phase.

_startup_phase("resolve_config", t0) runs before the config-driven initialize_logging(). When local or CLI configuration changes log_format or log_level, this startup record can still use the environment-based logger, leaving mixed-format startup output.

Move the phase timing after the comparison and reinitialization:

Proposed ordering
 resolved = resolve_run_configuration(config)
 apply_run_environment(resolved)
-_startup_phase("resolve_config", t0)

 service_config = get_common_service_config()
 if (...) :
     ...
     initialize_logging()
+_startup_phase("resolve_config", t0)
📝 Committable suggestion

‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.

Suggested change
t0 = time.perf_counter()
resolved = resolve_run_configuration(config)
apply_run_environment(resolved)
_startup_phase("resolve_config", t0)
# The config file may still override the environment (local / CLI use), so re-initialize
# logging when it disagrees with what the environment already configured.
service_config = get_common_service_config()
if otel_settings.log_format != service_config.log_format:
if (otel_settings.log_format, otel_settings.log_level) != (service_config.log_format, service_config.log_level):
otel_settings.log_format = service_config.log_format
if otel_settings.log_level != service_config.log_level:
otel_settings.log_level = service_config.log_level
t0 = time.perf_counter()
initialize_obs(resource_attributes=get_platform_resource_attributes())
setup_global_instrumentations()
_startup_phase("observability_init", t0)
initialize_logging()
t0 = time.perf_counter()
resolved = resolve_run_configuration(config)
apply_run_environment(resolved)
# The config file may still override the environment (local / CLI use), so re-initialize
# logging when it disagrees with what the environment already configured.
service_config = get_common_service_config()
if (otel_settings.log_format, otel_settings.log_level) != (service_config.log_format, service_config.log_level):
otel_settings.log_format = service_config.log_format
otel_settings.log_level = service_config.log_level
initialize_logging()
_startup_phase("resolve_config", t0)
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@packages/nmp_platform_runner/src/nmp/platform_runner/run.py` around lines 97
- 108, Move _startup_phase("resolve_config", t0) in the run configuration flow
to after the service_config comparison and any initialize_logging() call, while
preserving the existing timing start and logging reinitialization behavior.

@github-actions

Copy link
Copy Markdown
Contributor
Suite Lines Covered Line Rate Branch Rate
Unit Tests 27157/34871 77.9% 62.1%
Integration Tests 15969/33582 47.5% 20.0%

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

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant