Skip to content

Fix: replace verbose log tiers with severity levels - #1475

Open
zmnobug wants to merge 1 commit into
hw-native-sys:mainfrom
zmnobug:refactor/issue-1429-log-levels
Open

Fix: replace verbose log tiers with severity levels#1475
zmnobug wants to merge 1 commit into
hw-native-sys:mainfrom
zmnobug:refactor/issue-1429-log-levels

Conversation

@zmnobug

@zmnobug zmnobug commented Jul 25, 2026

Copy link
Copy Markdown
Contributor

Summary

  • replace the V0-V9 verbosity tiers with DEBUG, INFO, TIMING, WARN, and ERROR, defaulting to TIMING
  • carry one threshold consistently through Python, host logging, simulation AICPU libraries, and onboard CANN configuration
  • move STRACE markers to TIMING, migrate affected call sites and documentation, and retain the log-footprint reduction from Strip all LOG_* call sites — logging re-tiering baseline #1447
  • add regressions for CANN threshold mapping and simulation AICPU threshold propagation

Testing

  • editable package build
  • 78 focused Python logging/worker tests
  • 60 C++ unit tests
  • a2a3sim STRACE and AICPU debug propagation tests
  • a5sim AICPU debug propagation test
  • a2a3 onboard STRACE/device-wall test
  • full Python, a2a3sim, and a5sim suites before the final rebase

Performance

On a2a3 batch_paged_attention Case1 over 100 rounds:

  • device time: 4561.0 us -> 4349.7 us (-4.63%)
  • effective time: 4536.7 us -> 4324.9 us (-4.67%)
  • device INFO lines: 6299 -> 0

Fixes #1429

@coderabbitai

coderabbitai Bot commented Jul 25, 2026

Copy link
Copy Markdown

Important

Review skipped

Too many files!

This PR contains 156 files, which is 56 over the limit of 100.

To get a review, narrow the scope:
• coderabbit review --committed # exclude uncommitted changes
• coderabbit review --dir # limit to a subdirectory
• coderabbit review --base # compare against a closer base

Upgrade to a paid plan to raise the limit.

This review couldn't start because sufficient usage credits or metered capacity aren't available. Add credits or update usage-based reviews in the billing tab, then retry.

⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: 1da6f067-9e58-4670-b90c-72f271a0015a

📥 Commits

Reviewing files that changed from the base of the PR and between 1f88886 and 45d062e.

📒 Files selected for processing (156)
  • .claude/skills/multi-repo-qwen-setup/SKILL.md
  • conftest.py
  • docs/chip-level-arch.md
  • docs/dfx/device-phases.md
  • docs/dfx/host-trace.md
  • docs/dfx/l2-swimlane-profiling.md
  • docs/dynamic-linking.md
  • docs/getting-started.md
  • docs/logging.md
  • docs/testing.md
  • docs/troubleshooting/device-error-codes/stall.md
  • examples/a2a3/tensormap_and_ringbuffer/benchmark_bgemm/kernels/orchestration/bgemm_orch.cpp
  • examples/a2a3/tensormap_and_ringbuffer/paged_attention/kernels/orchestration/paged_attention_orch.cpp
  • examples/a2a3/tensormap_and_ringbuffer/paged_attention_manual_scope/kernels/orchestration/paged_attention_orch.cpp
  • examples/a2a3/tensormap_and_ringbuffer/paged_attention_unroll_manual_scope/kernels/orchestration/paged_attention_orch.cpp
  • examples/a2a3/tensormap_and_ringbuffer/scalar_data/kernels/orchestration/scalar_data_orch.cpp
  • examples/a2a3/tensormap_and_ringbuffer/vector_example/kernels/orchestration/example_orchestration.cpp
  • examples/a5/tensormap_and_ringbuffer/bgemm/kernels/orchestration/bgemm_orch.cpp
  • examples/a5/tensormap_and_ringbuffer/paged_attention/kernels/orchestration/paged_attention_orch.cpp
  • examples/a5/tensormap_and_ringbuffer/paged_attention_manual_scope/kernels/orchestration/paged_attention_orch.cpp
  • examples/a5/tensormap_and_ringbuffer/paged_attention_unroll_manual_scope/kernels/orchestration/paged_attention_orch.cpp
  • examples/a5/tensormap_and_ringbuffer/vector_example/kernels/orchestration/example_orchestration.cpp
  • examples/workers/l2/vector_add/test_run_timing.py
  • python/bindings/task_interface.cpp
  • python/simpler/__init__.py
  • python/simpler/_log.py
  • python/simpler/task_interface.py
  • python/simpler/worker.py
  • simpler_setup/log_config.py
  • simpler_setup/scene_test.py
  • simpler_setup/tools/README.md
  • simpler_setup/tools/strace_timing.py
  • simpler_setup/tools/swimlane_converter.py
  • src/a2a3/platform/include/common/kernel_args.h
  • src/a2a3/platform/include/host/pmu_collector.h
  • src/a2a3/platform/onboard/aicpu/kernel.cpp
  • src/a2a3/platform/onboard/host/aicpu_topology_probe.cpp
  • src/a2a3/platform/onboard/host/comm_hccl.cpp
  • src/a2a3/platform/onboard/host/device_runner.cpp
  • src/a2a3/platform/shared/host/pmu_collector.cpp
  • src/a2a3/platform/sim/host/device_runner.cpp
  • src/a2a3/runtime/host_build_graph/aicpu/aicpu_executor.cpp
  • src/a2a3/runtime/host_build_graph/docs/device_log_profiling.md
  • src/a2a3/runtime/host_build_graph/docs/profiling_levels.md
  • src/a2a3/runtime/host_build_graph/host/dep_gen_host_graph.cpp
  • src/a2a3/runtime/host_build_graph/host/runtime_maker.cpp
  • src/a2a3/runtime/host_build_graph/orchestration/pto_orchestration_api.h
  • src/a2a3/runtime/host_build_graph/runtime/orchestrator_core/pto_runtime2.cpp
  • src/a2a3/runtime/host_build_graph/runtime/pto_runtime2.h
  • src/a2a3/runtime/host_build_graph/runtime/scheduler/scheduler_cold_path.cpp
  • src/a2a3/runtime/host_build_graph/runtime/scheduler/scheduler_dispatch.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/docs/device_log_profiling.md
  • src/a2a3/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md
  • src/a2a3/runtime/tensormap_and_ringbuffer/host/dep_gen_replay.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/host/runtime_maker.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/orchestration/pto_orchestration_api.h
  • src/a2a3/runtime/tensormap_and_ringbuffer/runtime/pto_runtime2.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/runtime/pto_runtime2.h
  • src/a2a3/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp
  • src/a2a3/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp
  • src/a5/platform/include/common/kernel_args.h
  • src/a5/platform/include/host/pmu_collector.h
  • src/a5/platform/onboard/aicpu/kernel.cpp
  • src/a5/platform/onboard/host/aicpu_topology_probe.cpp
  • src/a5/platform/onboard/host/comm_hccl.cpp
  • src/a5/platform/onboard/host/device_runner.cpp
  • src/a5/platform/shared/host/pmu_collector.cpp
  • src/a5/platform/sim/host/device_runner.cpp
  • src/a5/runtime/host_build_graph/aicpu/aicpu_executor.cpp
  • src/a5/runtime/host_build_graph/host/runtime_maker.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/docs/device_log_profiling.md
  • src/a5/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md
  • src/a5/runtime/tensormap_and_ringbuffer/host/dep_gen_replay.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/host/runtime_maker.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/orchestration/pto_orchestration_api.h
  • src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_runtime2.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_runtime2.h
  • src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp
  • src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp
  • src/common/aicpu_loader/host/load_aicpu_op.cpp
  • src/common/log/host_log.cpp
  • src/common/log/include/common/log_level.h
  • src/common/log/include/common/strace.h
  • src/common/log/include/common/unified_log.h
  • src/common/log/include/host_log.h
  • src/common/log/unified_log_host.cpp
  • src/common/platform/include/aicpu/device_log.h
  • src/common/platform/onboard/aicpu/device_log.cpp
  • src/common/platform/onboard/aicpu/platform_aicpu_affinity.cpp
  • src/common/platform/onboard/host/c_api_shared.cpp
  • src/common/platform/onboard/host/device_runner_base.cpp
  • src/common/platform/shared/aicpu/args_dump_aicpu.cpp
  • src/common/platform/shared/aicpu/dep_gen_collector_aicpu.cpp
  • src/common/platform/shared/aicpu/l2_swimlane_collector_aicpu.cpp
  • src/common/platform/shared/aicpu/scope_stats_collector_aicpu.cpp
  • src/common/platform/shared/aicpu/unified_log_device.cpp
  • src/common/platform/shared/host/args_dump_collector.cpp
  • src/common/platform/shared/host/dep_gen_collector.cpp
  • src/common/platform/shared/host/l2_swimlane_collector.cpp
  • src/common/platform/shared/host/scope_stats_collector.cpp
  • src/common/platform/sim/aicpu/device_log.cpp
  • src/common/platform/sim/aicpu/platform_aicpu_affinity.cpp
  • src/common/platform/sim/host/device_runner_base.cpp
  • src/common/platform/sim/sim_context/cpu_sim_context.cpp
  • src/common/worker/pto_runtime_c_api.h
  • tests/st/a2a3/host_build_graph/available_aicore_counts/kernels/orchestration/available_aicore_counts_orch.cpp
  • tests/st/a2a3/host_build_graph/bgemm/kernels/orchestration/bgemm_orch.cpp
  • tests/st/a2a3/host_build_graph/dump_args/kernels/orchestration/dump_args_orch.cpp
  • tests/st/a2a3/host_build_graph/matmul/kernels/orchestration/matmul_orch.cpp
  • tests/st/a2a3/host_build_graph/paged_attention/kernels/orchestration/paged_attention_orch.cpp
  • tests/st/a2a3/host_build_graph/vector_example/kernels/orchestration/example_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/alternating_matmul_add/kernels/orchestration/alternating_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/available_aicore_counts/kernels/orchestration/available_aicore_counts_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/batch_paged_attention/kernels/orchestration/paged_attention_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/dfx/l2_swimlane/kernels/orchestration/chained_mix_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/dummy_task/kernels/orchestration/dummy_task_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/mixed_example/kernels/orchestration/mixed_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/paged_attention_unroll/kernels/orchestration/paged_attention_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_basic/kernels/orchestration/spmd_basic_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_batch_dispatch_oob/kernels/orchestration/spmd_batch_dispatch_oob_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_multiblock_aiv/kernels/orchestration/spmd_multiblock_aiv_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_multiblock_mix/kernels/orchestration/spmd_multiblock_mix_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_paged_attention/kernels/orchestration/spmd_paged_attention_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_paged_attention_highperf/kernels/orchestration/paged_attention_highperf_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_starvation/kernels/orchestration/spmd_starvation_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start/kernels/orchestration/spmd_sync_start_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start_aiv/kernels/orchestration/spmd_sync_start_aiv_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start_early_dispatch/kernels/orchestration/spmd_sync_start_early_dispatch_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start_edge/kernels/orchestration/spmd_sync_start_edge_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start_mix_spill/kernels/orchestration/spmd_sync_start_mix_spill_orch.cpp
  • tests/st/a2a3/tensormap_and_ringbuffer/spmd_sync_start_stress/kernels/orchestration/spmd_sync_start_stress_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/available_aicore_counts/kernels/orchestration/available_aicore_counts_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/dfx/l2_swimlane/kernels/orchestration/chained_mix_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/dummy_task/kernels/orchestration/dummy_task_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/mixed_example/kernels/orchestration/mixed_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/paged_attention_unroll/kernels/orchestration/paged_attention_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_basic/kernels/orchestration/spmd_basic_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_multiblock_aiv/kernels/orchestration/spmd_multiblock_aiv_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_multiblock_mix/kernels/orchestration/spmd_multiblock_mix_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_starvation/kernels/orchestration/spmd_starvation_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start/kernels/orchestration/spmd_sync_start_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start_aiv/kernels/orchestration/spmd_sync_start_aiv_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start_early_dispatch/kernels/orchestration/spmd_sync_start_early_dispatch_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start_edge/kernels/orchestration/spmd_sync_start_edge_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start_mix_spill/kernels/orchestration/spmd_sync_start_mix_spill_orch.cpp
  • tests/st/a5/tensormap_and_ringbuffer/spmd_sync_start_stress/kernels/orchestration/spmd_sync_start_stress_orch.cpp
  • tests/st/aicore_op_timeout/kernels/orchestration/aicore_op_timeout_orch.cpp
  • tests/ut/cpp/a2a3/test_a2a3_fatal.cpp
  • tests/ut/cpp/a2a3/test_aicpu_affinity_select.cpp
  • tests/ut/cpp/a5/test_a5_fatal.cpp
  • tests/ut/cpp/a5/test_host_log_off.cpp
  • tests/ut/cpp/stubs/test_stubs.cpp
  • tests/ut/py/test_log_config.py
  • tests/ut/py/test_worker/test_host_worker.py

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.


Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

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

@zmnobug
zmnobug force-pushed the refactor/issue-1429-log-levels branch 4 times, most recently from 873df6e to 2d4b378 Compare July 27, 2026 03:36
ChaoWao added a commit that referenced this pull request Jul 27, 2026
docs/ had 35 files flat at its root with no index. The top-level README
listed 10 of them, so the other 25 were discoverable only by grep, and
four had no inbound link from anywhere in the repo. Only investigations/
carried a README; dfx/ (12 files, 5227 lines), troubleshooting/ and
hardware/ had none.

- Add docs/README.md indexing every root document and subdirectory,
  grouped by reader intent, and stating that a new doc registers there
  in the same commit. This de-orphans install.md, simt-launch.md,
  profiling-config-naming.md and sim_multi_device_isolation.md.
- Add docs/capability-survey.md: a status snapshot of what is shipped,
  gated, or design-only across the level model (L2 chip up to L4
  host-to-host), the CANN launch surface for AICore and AICPU, and the
  communication engines. Every claim carries a file:line so it can be
  re-checked, and the page records the snapshot commit because status
  claims rot faster than architecture.
- Move profiling-framework.md, profiling-name-map.md and
  profiling-config-naming.md into docs/dfx/, which already held 12
  profiling documents and linked up to these three nine times via ../.
  Add docs/dfx/README.md as that directory's index.
  logging.md stays at the docs/ root: PR #1475 modifies it, so renaming
  it here would hand that author a rename-vs-modify conflict.
- Fix seven broken links in docs/dfx/pmu-profiling.md, a file already
  touched by this change: six had the wrong relative depth
  (../src -> ../../src) and profiling_copy.h moved to src/common/ when
  #944 unified the collector framework.
@zmnobug
zmnobug force-pushed the refactor/issue-1429-log-levels branch 3 times, most recently from a8d5c26 to accb802 Compare July 28, 2026 09:37
- Collapse V0-V9 call sites to INFO and reserve TIMING for STRACE
- Add DEBUG, TIMING, WARN, and ERROR severity APIs
- Default to TIMING and align Python, host, sim, and CANN thresholds
- Forward the threshold into RTLD_LOCAL AICPU simulation libraries
- Add CANN configuration and simulation propagation regressions
- Update affected call sites and documentation

Fixes hw-native-sys#1429

Co-authored-by: ChaoZheng109 <zhengchao47@huawei.com>
@zmnobug
zmnobug force-pushed the refactor/issue-1429-log-levels branch from accb802 to 45d062e Compare July 28, 2026 11:08
@ChaoZheng109

Copy link
Copy Markdown
Collaborator

Stale reference to a removed symbol — tests/st/a5/tensormap_and_ringbuffer/bench_prewarm_timing.py:69

# line 25
from simpler import _log
# line 69
logging.getLogger("simpler").setLevel(_log.V9)

This PR deletes V0..V9 from python/simpler/_log.py (only TIMING / NUL remain), but bench_prewarm_timing.py still references _log.V9. Running the script now raises AttributeError: module 'simpler._log' has no attribute 'V9'.

The file isn't part of this PR's diff, so a line-anchored inline comment can't be attached here — flagging it at the conversation level instead. It's also why CI stays green: the filename isn't test_*, pytest doesn't collect it, and nothing else invokes it — so it's dead-on-arrival only if run manually. A repo-wide grep for V0..V9 / _log.V references (per .claude/rules/doc-consistency.md §1) would have caught it.

Suggested fix: _log.V9 -> _log.TIMING (V9 was the must-see tier STRACE used; TIMING is its successor and keeps the benchmark's "maximize timing visibility" intent).

void init_log_switch() {
g_is_log_enable_debug = CheckLogLevel(AICPU, DLOG_DEBUG);
g_is_log_enable_info = CheckLogLevel(AICPU, DLOG_INFO);
g_is_log_enable_timing = CheckLogLevel(AICPU, DLOG_WARN);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

host/device log-level should stay aligned: onboard can't suppress TIMING at --log-level warn.

Gating TIMING on CheckLogLevel(AICPU, DLOG_WARN) makes g_is_log_enable_timing identical to g_is_log_enable_warn, so onboard can never separate the two. At --log-level warn (threshold 30):

  • host: is_enabled(TIMING) -> 25 >= 30 is false -> TIMING suppressed ✓
  • sim device: this PR forwards the threshold into set_log_level, which gates g_is_log_enable_timing = level <= 25 independently -> TIMING suppressed ✓
  • onboard device: TIMING still emits (shares the DLOG_WARN flag) ✗

So after this PR sim and onboard disagree on the timing/warn boundary, and neither matches the host only for onboard. There are no device LOG_TIMING call sites today, but the level semantics should still line up across host and both device backends so a future device-side TIMING log behaves consistently.

Cheap fix, no new plumbing — the threshold already reaches the device: kernel.cpp calls set_log_level(init_args->log_level). Instead of making onboard's set_log_level a no-op, store the threshold in a simpler-owned global and gate is_log_enable_timing() on threshold <= TIMING(25) (mirroring sim, and the old g_log_info_v simpler-managed axis). Keep DEBUG/INFO/WARN/ERROR on CANN as-is; only TIMING needs the simpler-side cut, since CANN has no level between INFO and WARN.

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.

[Code Health] Re-tier log levels: replace V0..V9 with debug/info/timing/warn/error; fix CANN dlog INFO seeding (a2a3 + a5)

2 participants