Skip to content
Merged
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
188 changes: 188 additions & 0 deletions .agents/skills/sftrace/SKILL.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,188 @@
---
name: sftrace
description: Use sftrace, which is based on LLVM Xray instrumentation, to trace all Rust function calls. This can be used for performance analysis and troubleshooting.
Comment thread
stormslowly marked this conversation as resolved.
---

# Rspack Resolver Sftrace

## Overview

Use sftrace (LLVM XRay) to trace rspack-resolver's Rust function calls and convert them to perfetto protobuf format for performance analysis and troubleshooting.

Default workflow: run from the project root and store all trace artifacts in a `sftrace-<timestamp>` directory.

## Workflow

### 1) Build sftrace tools

```sh
git clone https://github.com/quininer/sftrace
cd sftrace
cargo build --release
mkdir "$(./target/release/sftrace record --print-solib-install-dir)"
cp ./target/release/libsftrace.so "$(./target/release/sftrace record --print-solib-install-dir)/"
Comment thread
stormslowly marked this conversation as resolved.
```
Comment on lines +19 to +24

### 2) Build with XRay instrumentation

XRay instrumentation must be enabled via RUSTFLAGS. There are two targets: the Node.js binding and the Rust benchmark binary.

#### 2a) Node.js binding

```sh
RUSTFLAGS="-Zinstrument-xray=always" pnpm build:binding:profiling
```

The `.node` binding file will be output to the project root (e.g. `resolver.darwin-arm64.node`).
Comment thread
stormslowly marked this conversation as resolved.

#### 2b) Benchmark binary

```sh
RUSTFLAGS="-Zinstrument-xray=always" cargo +nightly bench --profile profiling --no-run
```
Comment on lines +28 to +42

The benchmark binary will be output under `target/profiling/deps/`. Find it with:

```sh
BENCH_BIN="$(ls -t target/profiling/deps/resolver-* | grep -v '\.d$' | head -1)"
```
Comment on lines +47 to +48
Copy link
Copy Markdown

Choose a reason for hiding this comment

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

medium

The command to define BENCH_BIN is repeated several times throughout the document (e.g., lines 47-48, 58-59, 83-84). To improve maintainability and reduce redundancy, consider defining this variable once at the beginning of the 'Workflow' section or at least before its first use, and then referencing it. This ensures that if the naming convention or path changes, only one place needs to be updated.

Suggested change
BENCH_BIN="$(ls -t target/profiling/deps/resolver-* | grep -v '\.d$' | head -1)"
```
BENCH_BIN="$(ls -t target/profiling/deps/resolver-* | grep -v '\.d$' | head -1)"


### 3) Optional: Generate a filter file from symbols

`sftrace filter` works on function symbols from an object file (`.node` binding or benchmark binary).

```sh
# For Node.js binding
TARGET="$(ls resolver.*.node | head -1)"
Comment thread
stormslowly marked this conversation as resolved.

# For benchmark binary
TARGET="$(ls -t target/profiling/deps/resolver-* | grep -v '\.d$' | head -1)"

# Regex mode
sftrace filter -p "$TARGET" -r 'resolve|normalize|cache' -o sftrace.filter

# List mode (one regex per line)
# sftrace filter -p "$TARGET" --list symbols.list -o sftrace.filter
```

### 4) Record sftrace

```sh
TRACE_DIR="sftrace-$(date +%Y%m%d-%H%M%S)"
mkdir -p "$TRACE_DIR"
```

#### 4a) Trace Node.js binding (e.g. run tests)

```sh
sftrace record -o "$TRACE_DIR/sf.log" -- pnpm test
```

#### 4b) Trace benchmark binary

```sh
BENCH_BIN="$(ls -t target/profiling/deps/resolver-* | grep -v '\.d$' | head -1)"

# Full trace
sftrace record -o "$TRACE_DIR/sf.log" -- "$BENCH_BIN" --bench
Comment on lines +86 to +87
Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P1 Badge Remove the unsupported --bench flag from direct bench runs

These commands execute the compiled benchmark binary directly, but this repo’s bench target is harness = false (Cargo.toml:23-25) and uses criterion_main!(resolver) (benches/resolver.rs:357-358). In codspeed-criterion-compat, that generated main only parses an optional positional FILTER and --exact, so passing libtest’s --bench flag makes the binary exit on an unknown argument instead of recording any trace.

Useful? React with 👍 / 👎.

Comment thread
stormslowly marked this conversation as resolved.

# Filtered trace (requires sftrace.filter from step 3)
sftrace record -f sftrace.filter -o "$TRACE_DIR/sf.filtered.log" -- "$BENCH_BIN" --bench
```

`--bench` tells criterion to run in benchmark mode. You can append `-- <filter>` to run only specific benchmarks (e.g. `-- "resolve_node_modules"`).

### 5) Optional: Analyze sf.log by [polars](https://docs.pola.rs/)

Convert sftrace log to polars dataframe.

```sh
TRACE_DIR="sftrace-YYYYMMDD-HHMMSS" # replace with your run directory
Comment thread
stormslowly marked this conversation as resolved.
sftrace convert --type pola "$TRACE_DIR/sf.log" -o "$TRACE_DIR/sf.pola"
```

This will generate two files, whose schema format is as follows:

1. sf.pola

This records all events from sftrace log.

| name | type | description |
| -------- | ----------- | -------------------------------------------------------------------------- |
| frame_id | uint64 | a unique id for each frame. a function's entry and exit have same frame id |
| parent | uint64 | point to previous frame id. zero means non-existent |
| tid | uint32 | thread id |
Comment on lines +110 to +114
| func_id | uint64 | function unique id |
| time | nanoseconds | time elapsed since program started |
| kind | uint32 | event type, 1 is entry, 2 is exit, 3 is tail call |

2. sf.pola.symtab

This records the function symbol name and file path of `func_id`.

| name | type | description |
| ------- | ------ | ----------------------------------------- |
| func_id | uint64 | function unique id |
| name | string | function symbol name (demangled) |
| path | string | the file path and line number of function |
Comment thread
stormslowly marked this conversation as resolved.

You can use `python-polars` to perform data analysis on `sf.pola`.

```python
import polars as pl

sf = pl.scan_parquet("./sf.pola")
symtab = pl.scan_parquet("./sf.pola.symtab")

# Query the functions that appear most frequently
(
sf
.filter(pl.col("kind").eq(1))
.group_by("func_id")
.agg(pl.len().alias("func_count"))
.top_k(10, by="func_count")
.join(symtab, on="func_id")
.collect()
)

# Query the leaf frame of longest execution time
(
sf
.filter(~pl.col("frame_id").is_in(pl.col("parent").implode()))
.group_by("frame_id")
.agg([
pl.col("func_id").first(),
pl.col("time").filter(pl.col("kind").eq(1)).first().alias("entry_time"),
pl.col("time").filter(pl.col("kind").is_in([2, 3])).last().alias("exit_time"),
])
.filter(pl.col("exit_time").is_not_null())
.with_columns(pl.col("exit_time").sub("entry_time").alias("duration"))
.top_k(10, by="duration")
.join(symtab, on="func_id")
.collect()
)
```

### 6) Optional: Visualization sf.log

Convert sftrace log to perfetto protobuf format.

```sh
TRACE_DIR="sftrace-YYYYMMDD-HHMMSS" # replace with your run directory
sftrace convert "$TRACE_DIR/sf.log" -o "$TRACE_DIR/sf.pb.gz"
```

Visualization using [viztracer](https://github.com/gaogaotiantian/viztracer)

```sh
vizviewer --use_external_processor "$TRACE_DIR/sf.pb.gz"
```

Use this only for visualization.

## Filtering Notes

- `sftrace filter` matches function symbols by regex/list. It is not a first-class crate-path/module-path filter.
- Filtering does not automatically keep all descendants. If a child function symbol does not match your filter, it may disappear from the trace.
- Cross-thread relationships (for example via rayon) are not reconstructed as a single uninterrupted call chain.
- For complete call stacks, record without filter (or with a broad filter) and narrow down during analysis.
Loading