bytecodealliance / bytecodealliance/wasmtime

Per-function compilation diagnostics in cranelift_codegen should be trace, not debug

Open
#13,133 9 comments 1 reaction 0 assignees View on GitHub
Dominant language
Rust
Stars
18.6k
Forks
1.8k
Avg merge
1d 19h
Merged PRs (30d)
121

Description

I'll call out that I used AI to assist me with the analysis below. The desire to move us from trace=>debug from my experiences as a human. I validated that all the functions below are real and at `debug`. #NoAiSlop

## Summary

Several modules in `cranelift_codegen` and `wasmtime_internal_cranelift` emit per-function compilation statistics at `log::debug!` level. For any application that embeds wasmtime and sets `RUST_LOG=debug` to debug their own code, these messages completely drown out all other output. I'd like to suggest downgrading these per-function messages from `debug!` to `trace!`.

## Impact

I ran a workload that loaded 3 WASM modules. My actual application logic is small — the largest module has only 11 exported functions — but because WASM binaries include their full transitive dependency tree, cranelift ends up compiling ~4,100 functions total (most are from `core`, `alloc`, `regex`, `serde_json`, etc. linked into the binary). This is normal and expected for Rust-compiled WASM.

The resulting log file had **137,000 lines**, of which **136,480 (99.6%) were cranelift per-function compilation diagnostics**. My actual application produced only 520 lines (0.4%).

Breakdown by module:

| Module | Lines | % of total |
|--------|------:|:---:|
| `cranelift_codegen::timing::enabled` | 96,495 | 70.4% |
| `cranelift_codegen::machinst::compile` | 16,528 | 12.1% |
| `cranelift_codegen::context` | 12,396 | 9.0% |
| `wasmtime_internal_cranelift::compiler` | 6,929 | 5.1% |
| `cranelift_codegen::remove_constant_phis` | 4,132 | 3.0% |
| **All cranelift** | **136,480** | **99.6%** |
| Application logs | 520 | 0.4% |

That works out to ~33 debug log lines per compiled function. The only workaround today is to add per-module overrides like `RUST_LOG=debug,cranelift_codegen=info,wasmtime_cranelift=info,...` which is fragile and hard to discover.

## Affected source locations

These are the `log::debug!` calls that emit per-function messages:

**`cranelift/codegen/src/timing.rs`** (70% of volume — 2 lines × ~12 passes × every function):
```rust
// line 265
log::debug!(" {pass}, (during {prev})");
// line 295
log::debug!("timing: Ending {}: {}ms", self.pass, duration.as_millis());
```

**`cranelift/codegen/src/context.rs`** (9% — CLIF instruction/block counts and egraph stats per function):
```rust
// lines 156-160
log::debug!("Number of CLIF instructions to optimize: {}", ...);
log::debug!("Number of CLIF blocks to optimize: {}", ...);
// line 387
log::debug!("egraph stats: {:?}", pass.stats);
```

**`cranelift/codegen/src/machinst/compile.rs`** (12% — 4 messages per function):
```rust
log::debug!("Number of CLIF instructions to lower: {}", ...);
log::debug!("Number of CLIF blocks to lower: {}", ...);
log::debug!("Number of lowered vcode instructions: {}", ...);
log::debug!("Number of lowered vcode blocks: {}", ...);
```

**`cranelift/codegen/src/remove_constant_phis.rs`** (3% — 1 message per function):
```rust
log::debug!("do_remove_constant_phis: done, {} iters. ...", ...);
```

**`crates/cranelift/src/compiler.rs`** (5% — 2 messages per function):
```rust
log::debug!("`{symbol}` translated to CLIF in {:?}", timing.total());
log::debug!("`{symbol}` compiled in {:?}", timing.total());
```

## Suggested change

Change these per-function `log::debug!` calls to `log::trace!`. This would:

- Let embedders use `RUST_LOG=debug` without being flooded
- Keep the diagnostics fully available via `RUST_LOG=trace` for anyone who specifically wants them
- Align with the convention that `debug` is for occasional diagnostics and `trace` is for high-volume per-operation output

If the maintainers agree with this direction, I'd be glad to help with a PR. Thank you for all the great work on cranelift and wasmtime!

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.