Skip to content

【Hackathon 9th No.88】为FastDeploy重构log日志打印范式#6682

Draft
cloudforge1 wants to merge 4 commits intoPaddlePaddle:developfrom
cloudforge1:task/088-refactor-log-printing
Draft

【Hackathon 9th No.88】为FastDeploy重构log日志打印范式#6682
cloudforge1 wants to merge 4 commits intoPaddlePaddle:developfrom
cloudforge1:task/088-refactor-log-printing

Conversation

@cloudforge1
Copy link
Contributor

@cloudforge1 cloudforge1 commented Mar 5, 2026

Motivation

Refactor log printing in FastDeploy to establish a clear, readable, and well-organized logging paradigm.

Hackathon 9th — Task #88 | Task List

Task Deliverables

# Deliverable Description Link
D1 Research Doc FastDeploy logging current-state analysis (371 lines) See RFC PR appendix
D2 RFC Design Doc Logging paradigm refactor design (244 lines, 8 sections) PaddlePaddle/community#1220
D3 Implementation PR This PR — 38 files, +536/-261 This PR

Modifications

Phase A — Logging Infrastructure (Commit 1)

  1. Unified FD_LOG_LEVEL Environment Variable (fastdeploy/envs.py)

    • Added FD_LOG_LEVEL env var that supersedes FD_DEBUG toggle
    • Supports DEBUG, INFO, WARNING, ERROR, CRITICAL
    • Default: DEBUG when FD_DEBUG=1, otherwise INFO
  2. Logger Module Public API (fastdeploy/logger/__init__.py)

    • get_logger(name) factory returns namespaced loggers under fastdeploy.*
  3. Legacy Logger Unification (fastdeploy/logger/logger.py)

    • get_trace_logger() and _get_legacy_logger() now respect FD_LOG_LEVEL
  4. Console Handler (fastdeploy/logger/setup_logging.py)

    • Added console StreamHandler to fastdeploy root logger
  5. Model Base Migration (fastdeploy/model_executor/models/model_base.py)

    • Migrated print() to structured logger calls with lazy %s
  6. Unit Tests (tests/test_logging.py)

    • 13 unit tests across 5 test classes

Phase B — System-wide Migration (Commits 2-4)

  1. Config / Engine / Entrypoints (8 files)

    • config.py: verbose config dumps to logger.debug, f-string to %s
    • engine.py: internal debug messages demoted
    • common_engine.py, api_server.py, multi_api_server.py, serving_engine.py, serving_embedding.py, global_scheduler.py: lazy formatting
  2. Token Processor + Scheduler/Serving (12 files)

    • token_processor.py: 22 per-request logs INFO→DEBUG, 2 error handlers INFO→ERROR
    • Scheduler: dp_scheduler typo fix (Recieve→Receive), all 3 schedulers to DEBUG
    • serving_engine.py: _acquire_semaphore to DEBUG
  3. Model Executor + Entrypoints Completion (18 files)

    • model_executor/: 14 print()logger.debug/warning/info across 6 files
    • entrypoints/: per-request INFO→DEBUG with lazy %s across 12 files
    • splitwise_scheduler: per-request to DEBUG

Usage or Command

# Control log level via environment variable
export FD_LOG_LEVEL=DEBUG  # Options: DEBUG, INFO, WARNING, ERROR, CRITICAL

# Backward compatible with existing FD_DEBUG
export FD_DEBUG=1  # Sets DEBUG level (same as FD_LOG_LEVEL=DEBUG)

# Run unit tests
python -m pytest tests/test_logging.py -v

Accuracy Tests

  • Core module print() = 0 (excl subprocess strings, .print() methods)
  • Per-request INFO = 0 in serving paths (all downgraded to DEBUG)
  • All hot-path logger calls use %s lazy formatting (zero f-string .info() calls)
  • FD_LOG_LEVEL env variable controls all loggers
  • Full backward compatibility with FD_DEBUG=0/1
  • 13 unit tests passing

Checklist

  • Add at least a tag in the PR title.
  • Format your code, run pre-commit before commit.
  • Add unit tests.
  • Provide accuracy results. Logging refactor — validated by 13 unit tests.
  • If the current PR is submitting to the release branch, cherry-pick from develop. N/A — targeting develop.

@paddle-bot
Copy link

paddle-bot bot commented Mar 5, 2026

Thanks for your contribution!

@paddle-bot paddle-bot bot added the contributor External developers label Mar 5, 2026
@CLAassistant
Copy link

CLAassistant commented Mar 5, 2026

CLA assistant check
All committers have signed the CLA.

…sole handler, logger exports

- Add FD_LOG_LEVEL env var to envs.py (defaults based on FD_DEBUG)
- Populate fastdeploy/logger/__init__.py with get_logger() + exports
- Add console StreamHandler to unified fastdeploy logger
- Unify legacy loggers (get_trace_logger, _get_legacy_logger) to respect FD_LOG_LEVEL
- Migrate print()/f-string logger calls in model_base.py to lazy %s formatting
- Add 13 unit tests in tests/test_logging.py covering logger naming,
  FD_LOG_LEVEL env var, singleton pattern, console handler, legacy compat
…ing in config, engine, entrypoints, scheduler

- config.py: demote verbose config dumps to logger.debug, fix f-string → %s
- engine.py: demote internal debug messages, migrate f-strings to lazy formatting
- common_engine.py: migrate all f-string logger calls to lazy %s formatting
- api_server.py, multi_api_server.py: standardize log formatting
- serving_engine.py, serving_embedding.py: lazy formatting migration
- global_scheduler.py: migrate f-string logger calls to lazy %s formatting
…onfig/engine/scheduler/serving fixes

- token_processor.py: 22 per-request/internal logs INFO→DEBUG, 2 error handlers
  INFO→ERROR, 2 request completion summaries f-string→%s (kept INFO)
- config.py: parameter get/reset logs f-string→%s, sequence_parallel_moe→DEBUG
- engine.py: cache task→DEBUG, dp queue service f-string→%s
- common_engine.py: fix escaped quote syntax error in abort handler
- serving_engine.py: both _acquire_semaphore calls f-string→DEBUG+%s
- scheduler/: dp_scheduler typo fix (Recieve→Receive), all 3 schedulers
  enqueued/pulled/finished→DEBUG
- spec_logger single head accept ratio→DEBUG

Zero f-string .info() calls remain across all 12 target files.
All 12 files pass Python AST syntax validation.
…st INFO→DEBUG + f-string→%s

- model_executor/: 14 print() calls → logger.debug/warning/info (6 files)
  - graph_optimization/utils.py: memory info → debug
  - ops/gpu/__init__.py: sm_version → debug, module error → warning
  - models/adapters.py: load failure → warning
  - layers/attention/mla_attention_backend.py: flash attn detect → info
  - ops/triton_ops/triton_utils.py: kernel cache/compile → debug
  - ops/triton_ops/triton_utils_v2.py: kernel cache/compile → debug
- entrypoints/: per-request INFO → DEBUG with lazy %s (12 files)
  - engine_client.py: objgraph debug, max_tokens, control methods
  - serving_chat.py: create/release/stream per-request calls
  - serving_completion.py: init/preprocess/response per-request calls
  - v1/serving_chat.py, v1/serving_completion.py: stream/response
  - run_batch.py: startup/progress f-string → %s (keep INFO)
  - llm.py, chat_utils.py, serving_reward.py, utils.py, v1/serving_base.py
- scheduler/splitwise_scheduler.py: per-request → DEBUG, startup → INFO %s

Acceptance criteria met:
- Core module print() = 0 (excl subprocess string, .print() methods)
- Per-request INFO = 0 in serving paths (all downgraded to DEBUG)
- All hot-path logger calls use %s lazy formatting
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.

4 participants