Skip to content

Comments

feat(logging): improve worker log formatting and retry UX#65

Closed
deanq wants to merge 1 commit intomainfrom
deanq/ae-2146-better-printouts
Closed

feat(logging): improve worker log formatting and retry UX#65
deanq wants to merge 1 commit intomainfrom
deanq/ae-2146-better-printouts

Conversation

@deanq
Copy link
Contributor

@deanq deanq commented Feb 12, 2026

Summary

  • Configure uvicorn loggers (uvicorn, uvicorn.error, uvicorn.access) to use the same format as custom worker logs — eliminates the dual-format noise in container output
  • Change volume unpack retry attempts to 1-indexed (attempt 1 of 3 → readable) instead of attempt 0 of 3
  • Log non-final retry failures as WARNING (no traceback) instead of ERROR — reduces noise; final failure still raises
  • Add === 60-char section separators around key startup phases in unpack_volume.py and lb_handler.py to make container logs scannable at a glance

Test plan

  • All existing tests pass (240 tests, verified via pre-commit hook)
  • test_unpack_volume.py updated to assert new 1-indexed messaging and WARNING log level
  • No new dependencies; uv.lock not included in this PR
  • Quality checks pass: ruff format, ruff check, mypy, pytest

Files changed

File Change
src/logger.py Add uvicorn logger configuration to setup_logging()
src/lb_handler.py Add section header around mothership app import
src/unpack_volume.py 1-indexed retries, WARNING on non-final failures, section separators
tests/unit/test_unpack_volume.py Update assertions for new log behavior

- Configure uvicorn loggers to use same format as custom logs
- Change retry attempts to 1-indexed (1 of 3, not 0/3)
- Log retry failures as WARNING (not ERROR with traceback) for non-final attempts
- Add visual section separators (=== 60 chars) around key startup phases
- Add section header around mothership app import in lb_handler.py
- Update tests to match new logging behavior
Copy link
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

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

Pull request overview

This pull request improves the logging experience for worker-flash containers by standardizing log formats, improving retry UX, and adding visual section separators. The changes make container logs more scannable and reduce noise from expected retry failures.

Changes:

  • Configure uvicorn loggers to use the same format as custom worker logs, eliminating inconsistent formatting
  • Improve retry logging by using 1-indexed attempt numbers, logging non-final failures as WARNING instead of ERROR, and adding clear wait messages between retries
  • Add 60-character section separators around key startup phases to improve log scannability

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 2 comments.

File Description
src/logger.py Adds uvicorn logger configuration to unify log formatting across all loggers
src/unpack_volume.py Updates retry logic to use 1-indexed attempts, logs non-final failures as WARNING, and adds section separators
src/lb_handler.py Adds section separators around application import phase
tests/unit/test_unpack_volume.py Updates test assertions to match new logging behavior (WARNING for non-final failures, 1-indexed attempts)

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +61 to +68
formatter = logging.Formatter(fmt)
for logger_name in ["uvicorn", "uvicorn.error", "uvicorn.access"]:
uvicorn_logger = logging.getLogger(logger_name)
uvicorn_logger.setLevel(level)
# Suppress access logs unless DEBUG
if logger_name == "uvicorn.access" and level != logging.DEBUG:
uvicorn_logger.setLevel(logging.WARNING)
# Ensure handlers use our formatter
Copy link

Copilot AI Feb 12, 2026

Choose a reason for hiding this comment

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

Uvicorn loggers likely have no handlers at the time setup_logging() is called during module import, so this loop won't apply the formatter to any handlers. Uvicorn creates its handlers later when the server starts. Consider either adding handlers if they don't exist, or configuring uvicorn's logging via uvicorn's configuration options when starting the server.

Suggested change
formatter = logging.Formatter(fmt)
for logger_name in ["uvicorn", "uvicorn.error", "uvicorn.access"]:
uvicorn_logger = logging.getLogger(logger_name)
uvicorn_logger.setLevel(level)
# Suppress access logs unless DEBUG
if logger_name == "uvicorn.access" and level != logging.DEBUG:
uvicorn_logger.setLevel(logging.WARNING)
# Ensure handlers use our formatter
formatter = logging.Formter(fmt)
for logger_name in ["uvicorn", "uvicorn.error", "uvicorn.access"]:
uvicorn_logger = logging.getLogger(logger_name)
uvicorn_logger.setLevel(level)
# Suppress access logs unless DEBUG
if logger_name == "uvicorn.access" and level != logging.DEBUG:
uvicorn_logger.setLevel(logging.WARNING)
# Ensure each uvicorn logger has at least one handler so the formatter is applied
if not uvicorn_logger.handlers:
uvicorn_handler = logging.StreamHandler(stream)
uvicorn_handler.setFormatter(formatter)
uvicorn_logger.addHandler(uvicorn_handler)
# Ensure all handlers use our formatter

Copilot uses AI. Check for mistakes.
)
unpack_app_from_volume()
logger.info("=" * 60)
_UNPACKED = True
Copy link

Copilot AI Feb 12, 2026

Choose a reason for hiding this comment

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

The _UNPACKED flag is set to True here, but it was already set to True on line 129 at the start of the critical section. This assignment is redundant and can be removed.

Suggested change
_UNPACKED = True

Copilot uses AI. Check for mistakes.
@deanq
Copy link
Contributor Author

deanq commented Feb 13, 2026

Closing - breaks RunPod console logs due to uvicorn handler timing issue (race condition at import time). Will reopen with proper fix following runpod-python patterns.

@deanq deanq closed this Feb 13, 2026
@deanq deanq deleted the deanq/ae-2146-better-printouts branch February 13, 2026 00:24
deanq added a commit that referenced this pull request Feb 13, 2026
Implements better retry logging for volume unpacking with clearer distinction
between transient and terminal failures:
- 1-indexed retry attempts for user-friendliness
- WARNING level for expected retry failures (no traceback)
- ERROR level only on final failure (with traceback via exc_info=True)
- Clearer retry wait messages

Adds logger suppression pattern following runpod-python conventions:
- Suppress urllib3 and uvicorn loggers to reduce console noise
- Set to WARNING level in lb_handler at module import time
- Lets uvicorn handle its own logging with defaults

This avoids the earlier attempt to configure uvicorn handlers at import time
(which failed due to race condition with handler creation). Simple suppression
is cleaner and follows proven patterns from runpod-python.

Closes #65 (reverted broken changes but kept good retry improvements)
Co-Authored-By: Claude Haiku 4.5 <noreply@anthropic.com>
deanq added a commit that referenced this pull request Feb 13, 2026
Implements better retry logging for volume unpacking with clearer distinction
between transient and terminal failures:
- 1-indexed retry attempts for user-friendliness
- WARNING level for expected retry failures (no traceback)
- ERROR level only on final failure (with traceback via exc_info=True)
- Clearer retry wait messages

Adds logger suppression pattern following runpod-python conventions:
- Suppress urllib3 and uvicorn loggers to reduce console noise
- Set to WARNING level in lb_handler at module import time
- Lets uvicorn handle its own logging with defaults

This avoids the earlier attempt to configure uvicorn handlers at import time
(which failed due to race condition with handler creation). Simple suppression
is cleaner and follows proven patterns from runpod-python.

Closes #65 (reverted broken changes but kept good retry improvements)
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.

1 participant