diff --git a/Cargo.lock b/Cargo.lock index 7c65dad9b1..83e5bb1ffb 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4668,6 +4668,22 @@ dependencies = [ "rustversion", ] +[[package]] +name = "inferno" +version = "0.12.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "90807d610575744524d9bdc69f3885d96f0e6c3354565b0828354a7ff2a262b8" +dependencies = [ + "ahash 0.8.12", + "itoa", + "log", + "num-format", + "once_cell", + "quick-xml", + "rgb", + "str_stack", +] + [[package]] name = "inherit-methods-macro" version = "0.1.0" @@ -5620,6 +5636,16 @@ dependencies = [ "syn 2.0.117", ] +[[package]] +name = "num-format" +version = "0.4.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a652d9771a63711fd3c3deb670acfbe5c30a4072e664d7a3bf5a9e1056ac72c3" +dependencies = [ + "arrayvec", + "itoa", +] + [[package]] name = "num-integer" version = "0.1.46" @@ -6291,6 +6317,19 @@ dependencies = [ "anyhow", "bincode", "clap", + "inferno", + "object 0.37.3", + "regex", + "rustc-demangle", +] + +[[package]] +name = "quick-xml" +version = "0.39.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cdcc8dd4e2f670d309a5f0e83fe36dfdc05af317008fea29144da1a2ac858e5e" +dependencies = [ + "memchr", ] [[package]] @@ -8076,6 +8115,12 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a2eb9349b6444b326872e140eb1cf5e7c522154d69e7a0ffb0fb81c06b37543f" +[[package]] +name = "str_stack" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7f446288b699d66d0fd2e30d1cfe7869194312524b3b9252594868ed26ef056a" + [[package]] name = "strsim" version = "0.10.0" diff --git a/docs/harness-os-knowledge-graph.md b/docs/harness-os-knowledge-graph.md new file mode 100644 index 0000000000..639df9eede --- /dev/null +++ b/docs/harness-os-knowledge-graph.md @@ -0,0 +1,124 @@ +# Harness OS 知识图谱功能说明 + +`tools/starry-syscall-harness` 的 GUI 新增了一个独立的 `Knowledge` 页，用于在处理 StarryOS / ArceOS OS 相关 coding 任务时，自动扫描当前仓库并生成结构化知识图谱。 + +## 目标 + +该功能解决两个问题： + +1. 新接手任务时，需要快速知道当前代码改动落在 OS 哪个子系统。 +2. 写代码或做性能分析时，需要把仓库实践和 OS 课本知识关联起来，便于讲解、复盘和教学报告。 + +## 启动 + +```bash +python3 tools/starry-syscall-harness/harness.py ui --host 127.0.0.1 --port 8765 +``` + +浏览器打开： + +```text +http://127.0.0.1:8765/ +``` + +进入左侧 `Knowledge` tab。 + +## 页面能力 + +`Knowledge` 页面包含： + +* 当前开发任务输入框。 +* 粗粒度 / 细粒度讲解切换。 +* OS 子系统知识图谱 SVG。 +* 当前任务焦点节点高亮。 +* 节点详情面板。 + +点击图谱节点后，右侧会显示： + +* 子系统职责。 +* 相关目录。 +* 扫描到的代表文件。 +* 扫描到的 Rust 符号。 +* OS 课本知识。 +* 当前仓库实践关联。 + +## API + +GUI 使用以下本地 API： + +```text +GET /api/knowledge-graph?task=<当前任务>&granularity=coarse|fine&refresh=0|1 +``` + +也可以让当前 GUI 扫描相邻的本地教学仓库： + +```text +GET /api/knowledge-graph?repo_root=../tg-arceos-tutorial&task=分析教程实验&granularity=fine&refresh=1 +``` + +`repo_root` 为空时扫描当前仓库；非空时必须位于当前仓库或当前仓库的父目录下，且只用于静态扫描，不会通过 artifact API 暴露外部文件。 + +返回结构包含： + +* `graph.nodes`：OS 子系统节点。 +* `graph.edges`：子系统依赖边。 +* `task.focus_node_ids`：当前任务命中的焦点节点。 +* `focus.code_explanation`：代码讲解。 +* `focus.os_explanation`：OS 课本知识与实践关联。 +* `focus.coding_guidance`：编码建议。 + +## 扫描方式 + +当前实现是轻量本地静态扫描，不依赖外部服务： + +* 扫描 `os/`、`components/`、`drivers/`、`scripts/`、`tools/`、`test-suit/`、`docs/`。 +* 对教学仓库额外扫描 `app-*`、`exercise-*`、根 `README.md`、`report.md`、`Cargo.toml`。 +* 跳过 `.git`、`target`、`node_modules`、`__pycache__` 等目录。 +* 提取 `.rs`、`.toml`、`.py`、`.md`、`.c`、`.h`、`.json` 文件。 +* 根据预定义 OS 子系统目录、关键词、当前任务文本、未提交文件或最近提交文件进行匹配。 + +当前预置的主要节点包括： + +* Linux syscall compatibility +* Task / process lifecycle +* Scheduler / wait / synchronization +* Virtual memory / address space +* Allocator / object lifetime +* VFS / file I/O +* rsext4 / block cache +* Block layer / request queue +* virtio-blk driver +* Network stack / socket path +* virtio-net driver +* virtio-vsock / vhost-vsock +* PCI / interrupt / transport +* procfs / debug observability +* qperf / harness / GUI +* Build / rootfs / qemu tests + +## 粗/细粒度 + +`coarse`： + +* 面向任务入门和 PPT 总结。 +* 每个焦点节点只给职责、关键目录和 OS 概念关联。 + +`fine`： + +* 面向写代码和 code review。 +* 展示代表文件、符号、命中文件、实践风险和编码建议。 + +## 局限 + +* 当前是启发式静态扫描，不做完整 Rust 语义解析，也不构建精确调用图。 +* 任务焦点依赖目录、关键词、git diff 和最近提交文件，不能替代人工读代码。 +* 图谱节点是 OS 教学/工程视角下的子系统归类，不等价于 crate 依赖图。 +* 该功能不调用 LLM，因此讲解模板是确定性的；后续可接入更细的符号索引或 rustdoc JSON。 + +## 后续扩展建议 + +1. 读取 `Cargo.toml` workspace 和 crate dependency，补充 crate 依赖边。 +2. 用 `rustdoc --output-format json` 或 `cargo metadata` 生成更精确的符号图。 +3. 将 qperf report 的 hotspot category 自动映射到知识图谱节点。 +4. 在 GUI 的 qperf report 页点击 hotspot 时，跳转到对应知识图谱节点。 +5. 为每个节点补充课程章节、推荐阅读和典型 bug 模式。 diff --git a/docs/qperf-callchain-flamegraph-design.md b/docs/qperf-callchain-flamegraph-design.md new file mode 100644 index 0000000000..01d1d79883 --- /dev/null +++ b/docs/qperf-callchain-flamegraph-design.md @@ -0,0 +1,129 @@ +# qperf 深调用栈火焰图设计说明 + +## 1. 问题背景 + +旧版 qperf 生成的 `qperf/stack.folded` 大多只有一层函数名，因此 `flamegraph.svg` 只能横向展示 leaf hotspot，几乎没有纵向调用链。典型检查命令如下： + +```bash +awk -F';' '{print NF}' target/qperf-host-rerun/blk-harness/perf/riscv64/latest/qperf/stack.folded | sort -n | uniq -c +``` + +旧 blk 产物的结果为 `623 1`，说明 623 条 folded stack 全部只有一帧。结合 `resolve.stats.json` 中 `format_version=2`、`raw_records=1292`、`total_frames=1292`，可以判断当时 raw sample 本身只有 PC/TB leaf 地址，不是 analyzer 把多帧调用栈压扁了。 + +## 2. 根因诊断 + +本轮诊断结论如下： + +| 类别 | 结论 | +| --- | --- | +| raw sample 是否有 callchain | 旧格式没有，只有 elapsed timestamp 与 PC leaf。 | +| analyzer 是否压扁多帧 | 未发现多帧被压扁的问题；问题主要在采样侧没有多帧数据。 | +| QEMU plugin 是否读寄存器 | 旧执行回调使用 `QEMU_PLUGIN_CB_NO_REGS`，无法稳定读取 guest SP/FP。 | +| RISC-V FP 寄存器别名 | QEMU 暴露 `sp`、`fp`，同时也可能有 `x2`、`s0`、`x8` 别名；旧实现没有完整候选别名。 | +| 构建参数 | 旧 `--full-stack` 没有把 `-Cforce-frame-pointers=yes` 稳定传入实际 StarryOS kernel 构建。 | +| debug info | 只保留 leaf symbol 时还能解析函数名，但深栈与 inline 展开需要 `debuginfo=2` 与不剥离符号。 | + +因此，火焰图浅的核心原因不是 SVG 展示参数、采样频率或 `--max-depth`，而是 qperf 采样链路没有拿到可 unwind 的 guest callchain。 + +## 3. 实现方案 + +本轮采用真实 frame-pointer callchain 方案，默认仍保留 leaf 模式： + +| 模式 | 说明 | +| --- | --- | +| `leaf` | 默认模式，只记录 PC leaf，开销低、兼容旧命令。 | +| `fp` | 通过 QEMU TCG plugin 读取 guest `pc/sp/fp`，按 RISC-V frame pointer 链恢复调用栈。 | +| `logical` | 预留 CLI 值，但当前不实现；如果后续真实 unwind 不够稳定，再做人工插桩逻辑栈。 | + +`cargo starry perf --full-stack` 等价于： + +* 启用 qperf `callchain=fp`。 +* 为 StarryOS kernel 构建加入 `-Cdebuginfo=2`、`-Cstrip=none`、`-Cforce-frame-pointers=yes`。 +* 启用 `DWARF=y`、`BACKTRACE=y`，方便符号和 debug 信息保留。 + +## 4. raw sample v3 + +qperf plugin 新增 v3 sample 格式： + +```text +elapsed_ns +pc +sp +fp +cpu +callchain +trace[] +``` + +其中： + +* `pc` 是采样点 leaf PC。 +* `sp` 是 guest stack pointer。 +* `fp` 是 RISC-V `s0/fp`。 +* `trace[]` 是 plugin 通过 frame pointer unwind 得到的地址链。 +* `callchain=leaf|fp` 标记该样本来源。 + +analyzer 继续兼容旧 v1/v2 raw 格式；旧数据会自动退化为 leaf-only 栈。 + +## 5. RISC-V frame pointer unwind + +RISC-V ABI 下，开启 frame pointer 后通常可从当前 `fp` 附近读取上一个 frame pointer 与 return address。本轮实现按如下策略恢复： + +1. QEMU execute callback 使用 `QEMU_PLUGIN_CB_R_REGS`。 +2. 采样时读取 guest `sp` 与 `fp`，寄存器候选包括 `sp/x2` 与 `fp/s0/x8`。 +3. 只对 kernel text 或其物理映射别名范围内的 PC 做 unwind，避免在 OpenSBI 或用户态地址上误读。 +4. 按 `fp - 16` 读取 `{prev_fp, ra}`。 +5. 遇到非法地址、非单调 frame pointer、距离过大、循环 frame、不可读内存或非 kernel text return address 时停止。 +6. 单个样本 unwind 失败时回退到 leaf，不中断整个 profile。 + +输出新增： + +* `qperf/stack-depth-summary.csv` +* `report.json.callchain` +* `report.json.resolve_stats.depth_histogram` +* `qperf/summary.txt` 中的 sample format 与 callchain 字段 + +## 6. analyzer 与 folded stack + +analyzer 的变化： + +* 保留 raw sample 中的多帧地址，不再只按 leaf 聚合。 +* folded stack 按 caller-to-leaf 顺序输出。 +* `stack.folded` 默认保留完整 demangled Rust 路径。 +* `hotspots.csv` 继续提供函数热点聚合，但函数百分比按函数帧总量计算，避免深栈下出现超过 100% 的函数占比。 +* `hotspot_categories.csv` 是 inclusive stack 分类，表示某类别在多少条样本调用栈中出现，不是互斥 CPU 时间分摊。 + +## 7. cargo starry 集成 + +新增或完善的参数： + +```text +cargo starry perf --full-stack +cargo starry perf --perf-callchain leaf|fp|logical +cargo starry perf --perf-debuginfo +cargo starry perf --perf-force-frame-pointers +cargo starry perf --symbol-style full|module|short +cargo starry perf --max-depth 128 +``` + +推荐深栈用法： + +```bash +cargo starry perf \ + --case blk-full-stack \ + --full-stack \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' +``` + +默认 `cargo starry perf` 仍使用 `leaf`，避免对普通 profile 强制引入 frame pointer 与 debug info 的构建开销。 + +## 8. 局限性 + +* `fp` 模式依赖 kernel 编译时保留 frame pointer；没有 `--full-stack` 时不能期待深栈。 +* 目前只解析 kernel ELF，用户态符号和用户栈不是本轮目标。 +* trap/syscall/task 切换附近的栈可能截断，不能保证穿透所有上下文切换。 +* inline 展开会让 `stack.folded` 的符号层数大于 raw FP frame 数；原始地址深度以 `stack-depth-summary.csv` 为准。 +* QEMU 退出如果被 SIGKILL 截断，plugin shutdown summary 可能缺失；analyzer 仍可处理已落盘 raw sample。 +* `logical` 模式尚未实现，当前不会把人工 instrumentation 路径伪装成真实 CPU callchain。 diff --git a/docs/qperf-callchain-validation-report.md b/docs/qperf-callchain-validation-report.md new file mode 100644 index 0000000000..7d9d3752b7 --- /dev/null +++ b/docs/qperf-callchain-validation-report.md @@ -0,0 +1,346 @@ +# qperf 深调用栈火焰图优化验收报告 + +## 1. 验收目标 + +本轮验证要回答的问题： + +* qperf 火焰图浅是否确认为“只有 PC/TB leaf 采样”。 +* `--full-stack` / `--perf-callchain fp` 是否能生成真实纵向调用链。 +* folded stack 是否保留完整 Rust demangled 路径。 +* blk/net workload 是否能看到 syscall、fs/net、virtio、allocator、BTreeMap、memcpy/memmove 等路径。 +* 默认 leaf profile 是否保持兼容。 + +## 2. 验收环境 + +| 项目 | 值 | +| --- | --- | +| 仓库 commit | `34d0e92d5` | +| host | WSL2 Linux `5.15.167.4-microsoft-standard-WSL2` | +| CPU | Intel Core i7-14650HX，24 vCPU | +| QEMU | `qemu-system-riscv64` 10.2.1 | +| guest arch | `riscv64` | +| 运行方式 | 直接在宿主 WSL 环境运行，不在 Docker 中运行。本轮按用户已安装宿主 QEMU 的环境继续验证。 | +| host perf | 未启用 | +| qperf metrics | net case 启用，blk full-stack case 未启用 | + +当前工作区还包含本轮代码改动与此前未跟踪的文档/图片文件，验收报告只引用确认存在的 `target/qperf-callchain-validation/` 产物。 + +full-stack 构建后的 ELF 已做反汇编抽查，`VirtQueue::add_notify_wait_pop` prologue 中存在： + +```text +sd ra, 0x88(sp) +sd s0, 0x80(sp) +addi s0, sp, 0x90 +``` + +证据文件：`target/qperf-callchain-validation/full-stack-frame-pointer-objdump.txt`。这说明 `-Cforce-frame-pointers=yes` 已经进入实际 kernel 构建，而不是只停留在 CLI 参数层面。 + +## 3. 诊断结论 + +旧 blk 产物： + +```bash +awk -F';' '{print NF}' target/qperf-host-rerun/blk-harness/perf/riscv64/latest/qperf/stack.folded | sort -n | uniq -c +``` + +结果为： + +```text +623 1 +``` + +`resolve.stats.json` 显示旧 raw 格式为 v2，`raw_records=1292`、`total_frames=1292`，说明旧样本基本只有 leaf PC。根因是采样侧没有真实 callchain，而不是 flamegraph SVG 样式、采样频率或 analyzer 把多帧压扁。 + +## 4. 实现与验证矩阵 + +| 验收项 | 结果 | 证据路径 | 备注 | +| --- | --- | --- | --- | +| `cargo starry perf --help` 暴露 callchain 参数 | PASS | `target/qperf-callchain-validation/cargo-starry-perf-help.txt` | 包含 `--full-stack`、`--perf-callchain`、`--perf-debuginfo`、`--perf-force-frame-pointers`。 | +| harness `perf-profile --help` 暴露 callchain 参数 | PASS | `target/qperf-callchain-validation/harness-perf-profile-help.txt` | 包含 `--callchain`、`--full-stack`。 | +| leaf baseline 兼容 | PASS | `target/qperf-callchain-validation/blk-leaf/perf/riscv64/latest/report.json` | 默认 leaf 仍为一层栈。 | +| blk full-stack 深栈 | PASS | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/qperf/stack.folded` | 579 条 workload 样本中 578 条为多帧。 | +| net full-stack 深栈 | PASS | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/qperf/stack.folded` | 661 条 workload 样本中 652 条为多帧。 | +| `stack-depth-summary.csv` | PASS | `target/qperf-callchain-validation/*/perf/riscv64/latest/qperf/stack-depth-summary.csv` | 输出 raw FP trace depth 分布。 | +| `hotspots.csv` 深栈百分比 | PASS | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/hotspots.csv` | 函数热点百分比已按帧总量计算。 | +| net qperf metrics 合入 report | PASS | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/report.json` | `workload_metrics.values` 包含 virtio/net counters。 | +| logical stack fallback | N/A | 无 | 因真实 FP unwind 已可用，本轮未实现 logical stack；CLI 会明确拒绝该模式。 | + +## 5. leaf baseline + +命令： + +```bash +cargo starry perf \ + --case blk-leaf \ + --output-dir target/qperf-callchain-validation/blk-leaf \ + --host-time \ + --timeout 120 \ + --workload-timeout 75 \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --shell-init-cmd 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' \ + --no-truncate +``` + +结果： + +| 指标 | 值 | +| --- | ---: | +| result | `ok` | +| dd bytes | 53,601,104 | +| dd elapsed | 5.764698 s | +| dd throughput | 9,298,163 B/s | +| marker window | 5.832138317 s | +| boot samples excluded | 154 | +| selected records | 577 | +| selected multi-frame records | 0 | +| raw max depth | 1 | + +depth 分布： + +```text +depth,samples +1,577 +``` + +结论：默认 leaf 模式保持旧行为和低开销，但不会生成纵向火焰图。 + +## 6. blk full-stack + +命令： + +```bash +cargo starry perf \ + --case blk-full-stack \ + --output-dir target/qperf-callchain-validation/blk-full-stack \ + --full-stack \ + --host-time \ + --timeout 180 \ + --workload-timeout 120 \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --shell-init-cmd 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' \ + --no-truncate +``` + +结果： + +| 指标 | 值 | +| --- | ---: | +| result | `incomplete` | +| dd bytes | 53,601,104 | +| dd elapsed | 5.779240 s | +| dd throughput | 9,274,766 B/s | +| marker window | 5.845178559 s | +| boot samples excluded | 160 | +| post-window samples excluded | 1222 | +| selected records | 579 | +| selected multi-frame records | 578 | +| samples with FP | 578 | +| unwind success | 578 | +| report avg symbol depth | 43.887737478 | +| raw max depth | 18 | + +`stack-depth-summary.csv`： + +```text +depth,samples +1,1 +4,2 +5,2 +6,39 +7,2 +8,6 +9,42 +10,52 +11,44 +12,77 +13,41 +14,72 +15,183 +16,8 +17,7 +18,1 +``` + +`awk -F';' '{print NF}' .../stack.folded` 能看到 folded 符号层数最高到 72。层数大于 raw depth 的原因是 analyzer 通过 debug info 展开了 inline frame。 + +blk 关键路径已经能在 `stack.folded` 中看到： + +```text +starry_kernel::syscall::fs::io::sys_read + -> ax_fs_ng / rsext4 + -> ax_driver::block::binding::Block::read_blocks_wait + -> rd_block::CmdQueue::read_blocks_blocking + -> ax_driver::virtio::block::BlockQueue::submit_request + -> virtio_drivers::device::blk::VirtIOBlk::read_blocks + -> virtio_drivers::queue::VirtQueue::add_notify_wait_pop +``` + +top categories： + +| category | samples | percent | +| --- | ---: | ---: | +| block_io_path | 434 | 74.9568% | +| memcpy | 179 | 30.9154% | +| virtio_notify_kick | 176 | 30.3972% | +| virtqueue_add_notify_wait_pop | 173 | 29.8791% | +| lock_mutex_wait | 82 | 14.1623% | + +`result=incomplete` 的原因是 QMP stop 后 QEMU 在等待退出阶段被超时清理，导致 plugin shutdown summary 不完整；marker window、raw sample、folded stack 与 report 已生成。本项是 stop/shutdown 可靠性问题，不影响“是否能生成深调用栈”的结论。 + +## 7. net full-stack + +命令： + +```bash +cargo starry perf \ + --case net-full-stack \ + --output-dir target/qperf-callchain-validation/net-full-stack \ + --full-stack \ + --qperf-metrics \ + --host-time \ + --timeout 300 \ + --workload-timeout 240 \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:net; wget -O /dev/null http://10.0.2.2:8000/tmp/axbuild/rootfs/rootfs-riscv64-alpine.img.tar.xz; cat /proc/qperf_metrics; echo QPERF_END:net' \ + --no-truncate +``` + +结果： + +| 指标 | 值 | +| --- | ---: | +| result | `ok` | +| wget bytes | 63,543,705 | +| wget elapsed | 6.688766343 s | +| wget throughput | 9,500,063 B/s | +| marker window | 6.688766343 s | +| boot samples excluded | 159 | +| selected records | 661 | +| selected multi-frame records | 652 | +| samples with FP | 658 | +| unwind success | 652 | +| report avg symbol depth | 50.69591528 | +| raw max depth | 17 | + +`stack-depth-summary.csv`： + +```text +depth,samples +1,9 +3,3 +4,2 +5,1 +6,34 +7,7 +8,12 +9,8 +10,58 +11,136 +12,62 +13,93 +14,183 +15,45 +16,5 +17,3 +``` + +net 关键路径已经能在 `stack.folded` 中看到： + +```text +starry_kernel::syscall::fs::io::sys_readv + -> starry_kernel::file::net::Socket::read + -> ax_net_ng::SocketOps::recv + -> ax_net_ng::poll_interfaces + -> ax_net_ng::device::driver::RdNetDriver::prefetch_rx_packets + -> rd_net::RxQueue::receive / reclaim_packet + -> dma_api::array::ContiguousArray::read_with + -> compiler_builtins::mem::memcpy +``` + +net counters 已进入 `report.json.workload_metrics.values`： + +| counter | 值 | +| --- | ---: | +| virtqueue_add_count | 47,855 | +| virtio_notify_kick_count | 47,855 | +| virtqueue_pop_complete_count | 47,791 | +| virtqueue_add_notify_wait_pop_count | 1,177 | +| virtqueue_depth_max | 63 | +| virtio_net_rx_packets | 44,139 | +| virtio_net_rx_bytes | 65,935,922 | +| virtio_net_rx_copy_within_count | 44,139 | +| virtio_net_rx_copy_within_bytes | 65,935,922 | +| virtio_net_tx_packets | 2,476 | +| virtio_net_tx_staging_copy_bytes | 148,700 | +| virtio_net_inflight_insert_count | 46,678 | +| virtio_net_inflight_remove_count | 46,614 | +| virtio_net_inflight_get_count | 46,614 | + +top categories： + +| category | samples | percent | +| --- | ---: | ---: | +| net_rx_tx_path | 441 | 66.7171% | +| memcpy | 233 | 35.2496% | +| lock_mutex_wait | 100 | 15.1286% | +| memmove | 65 | 9.8336% | +| net_inflight_btree | 63 | 9.5310% | + +## 8. 证据文件 + +| 用途 | 路径 | +| --- | --- | +| blk leaf report | `target/qperf-callchain-validation/blk-leaf/perf/riscv64/latest/report.json` | +| blk leaf depth | `target/qperf-callchain-validation/blk-leaf/perf/riscv64/latest/qperf/stack-depth-summary.csv` | +| blk full-stack report | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/report.json` | +| blk full-stack flamegraph | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/qperf/flamegraph.svg` | +| blk full-stack workload flamegraph | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/qperf/flamegraph.workload.svg` | +| blk full-stack folded | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/qperf/stack.folded` | +| blk full-stack depth | `target/qperf-callchain-validation/blk-full-stack/perf/riscv64/latest/qperf/stack-depth-summary.csv` | +| net full-stack report | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/report.json` | +| net full-stack flamegraph | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/qperf/flamegraph.svg` | +| net full-stack workload flamegraph | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/qperf/flamegraph.workload.svg` | +| net full-stack folded | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/qperf/stack.folded` | +| net full-stack depth | `target/qperf-callchain-validation/net-full-stack/perf/riscv64/latest/qperf/stack-depth-summary.csv` | +| full-stack FP 反汇编抽查 | `target/qperf-callchain-validation/full-stack-frame-pointer-objdump.txt` | + +## 9. 验证命令 + +已执行： + +```bash +cargo fmt +cargo clippy --manifest-path tools/qperf/Cargo.toml -- -D warnings +cargo clippy --manifest-path tools/qperf/analyzer/Cargo.toml -- -D warnings +cargo clippy -p axbuild -- -D warnings +python3 -m py_compile tools/starry-syscall-harness/harness.py +``` + +其中 qperf clippy 初次发现两个手写 `% 8 == 0` 对齐判断，已改为 `is_multiple_of(8)` 后通过。 + +## 10. 局限性 + +* 默认模式仍是 leaf；只有 `--full-stack` 或 `--perf-callchain fp --perf-force-frame-pointers --perf-debuginfo` 才能期待深栈。 +* 当前 unwind 只覆盖 kernel symbol；用户态栈与用户 ELF symbol 尚未纳入。 +* trap、异常入口、任务切换、汇编 trampoline 仍可能截断调用链。 +* `report.json.callchain.avg_depth` 是 symbolized/inlined frame 平均层数；raw FP 地址深度以 `stack-depth-summary.csv` 为准。 +* `hotspot_categories.csv` 是 inclusive stack 归类，深栈下 allocator/scheduler 可能因为共同上层路径被频繁命中，不能按互斥 CPU 时间解读。 +* blk full-stack 本次 QEMU stop 结果为 `incomplete`，需要后续继续改善 QMP stop 与 plugin shutdown flush。 +* host perf/PMU 未启用，本报告不包含 host PMU 结论。 +* vsock 未在本轮补测；没有 `/dev/vhost-vsock` 的 host 不能做定量结论。 + +## 11. 结论 + +结论：PASS，针对“火焰图没有纵向延展”的 MVP 目标已经达成。 + +证据是： + +* leaf baseline 仍全部为一帧，复现了原问题。 +* `--full-stack` blk case 中 578/579 条 workload 样本为多帧，raw max depth 为 18，folded symbol depth 最高到 72。 +* `--full-stack` net case 中 652/661 条 workload 样本为多帧，raw max depth 为 17，folded symbol depth 最高到 78。 +* folded stack 中已经出现 syscall -> fs/net -> driver -> virtqueue/memcpy 的完整工程路径。 + +因此，现在 qperf 不再只能生成 leaf hotspot 火焰图；在 full-stack 模式下可以生成具备明显纵向展开的 RISC-V kernel flamegraph。默认 leaf 模式保留为低开销兼容路径。 diff --git a/docs/qperf-cargo-starry-integration-report.md b/docs/qperf-cargo-starry-integration-report.md new file mode 100644 index 0000000000..44c526d18c --- /dev/null +++ b/docs/qperf-cargo-starry-integration-report.md @@ -0,0 +1,179 @@ +# qperf 与 cargo starry 集成报告 + +## 1. 背景与目标 + +本轮目标是降低 qperf 使用门槛，并提升火焰图可读性： + +* 用户不再需要手写复杂 `tools/starry-syscall-harness/harness.py perf-profile ...`。 +* `cargo starry perf` 生成完整 qperf report、csv、folded stack、SVG flamegraph。 +* `cargo starry run --perf` 作为 `cargo starry qemu --perf` alias 路径，提供 run 语义入口。 +* 火焰图保留更完整的 Rust demangled symbol，支持 symbol style、focus、boot/workload/post/focused 视图。 + +本轮不修改 virtio 数据路径，也不宣称修复 virtio 性能问题。 + +## 2. 现有架构梳理 + +`.cargo/config.toml` 中 `cargo starry` 是 alias：`cargo run -p tg-xtask -- starry`。实际 StarryOS CLI 在 `scripts/axbuild/src/starry/mod.rs`，qperf runner 在 `scripts/axbuild/src/starry/perf.rs`。 + +本轮选择的集成点： + +* 保留并增强已有 `Command::Perf(ArgsPerf)`，即 `cargo starry perf`。 +* 给 `Command::Qemu(ArgsQemu)` 增加 `run` alias，并在 `ArgsQemu` 上增加 `--perf` 与 `--perf-*` 参数。 +* 继续复用 `perf::run()`，避免复制 qperf/QEMU/plugin/analyzer 逻辑。 +* 增加 harness `perf-postprocess`，让 cargo 入口也能生成与 harness 一致的 `report.json/report.md/hotspots.csv/hotspot_categories.csv`。 +* `cargo starry perf` 默认把 axbuild 临时目录隔离到输出目录下的 `axbuild-tmp/`；底层 `axbuild_tmp_dir()` 也支持 `AXBUILD_TMP_DIR`，避免已有 `tmp/axbuild/` 被 Docker/root-owned 文件污染时阻塞 profile。 + +## 3. 新命令设计 + +### `cargo starry perf` + +```bash +cargo starry perf --case boot +``` + +默认值： + +| 参数 | 默认值 | +| --- | --- | +| arch | `riscv64` | +| case | `boot` | +| output | `target/qperf//perf//latest/` | +| freq | `99` | +| max-depth | `128` | +| mode | `tb` | +| format | `all` | +| top | `80` | +| min-percent | `0.3` | +| host-time | enabled unless `--no-host-time` | + +### `cargo starry run --perf` + +`cargo starry run` 是 `cargo starry qemu` 的 alias。带 `--perf` 时转换为 `ArgsPerf` 并调用同一套 `perf::run()`： + +```bash +cargo starry run \ + --perf \ + --perf-case blk-read \ + --perf-workload 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' \ + --perf-start-marker QPERF_BEGIN \ + --perf-stop-marker QPERF_END \ + --perf-qperf-metrics +``` + +当前 `run --perf` 支持默认 qperf QEMU/rootfs flow，不支持和 `--qemu-config`、`--rootfs`、`--config`、`--target`、`--smp` 混用；这些组合会给出明确错误，避免静默忽略。 + +## 4. 火焰图增强 + +新增能力： + +* analyzer 支持 `--symbol-style full|short|module`。 +* analyzer fallback symtab 也会做 Rust demangle。 +* analyzer 支持 `--focus ` 生成聚焦 folded/flamegraph。 +* analyzer 支持 `--min-percent` 控制 SVG frame 最小宽度。 +* `cargo starry perf` 输出默认、workload、boot、post、focus 多个火焰图路径。 +* `--full-stack` 会把 qperf plugin max depth 至少提升到 256。 +* `--no-truncate` 会把 flamegraph min width 降到 0。 + +真实验证中，新 analyzer 已能把旧 `_R...` mangled symbol 转换为可读 Rust 路径，例如： + +```text +>::add_notify_wait_pop +::alloc +``` + +但当前 qperf 仍不保证恢复截图级完整调用栈。根因是 stack unwind 仍依赖 frame pointer 链，QEMU plugin sample 只记录 IP trace，没有 DWARF unwind 状态、vCPU/thread 元数据或 guest backtrace。 + +## 5. 使用示例 + +boot： + +```bash +cargo starry perf --case boot +``` + +blk-read： + +```bash +cargo starry perf \ + --case blk-read \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' +``` + +net-wget： + +```bash +cargo starry perf \ + --case net-wget \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:net-wget; wget -O /dev/null http://10.0.2.2:8000/tmp/axbuild/rootfs/rootfs-riscv64-alpine.img.tar.xz; cat /proc/qperf_metrics; echo QPERF_END:net-wget' +``` + +在 Docker/WSL 下，net server 应与 QEMU 处在可达网络拓扑中；此前验证显示 WSL host 上直接启动 HTTP server 时 guest 访问 `10.0.2.2:8000` 会 connection refused。 + +A/B compare： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/qperf/blk-read/perf/riscv64/latest/report.json \ + --candidate target/qperf/blk-read-patched/perf/riscv64/latest/report.json \ + --name blk-read-ab \ + --output-dir target/qperf/compare +``` + +## 6. 验收结果 + +| 验收项 | 结果 | 证据路径 | 备注 | +| --- | --- | --- | --- | +| qperf-analyzer help | PASS | `target/qperf-integration-smoke/help/qperf-analyzer-help.txt` | `--symbol-style`、`--focus`、`--min-percent` 出现在 help | +| harness perf-profile help | PASS | `target/qperf-integration-smoke/help/harness-perf-profile-help.txt` | 旧 harness 入口保留，并暴露新增 flamegraph 参数 | +| harness perf-postprocess help | PASS | `target/qperf-integration-smoke/help/harness-perf-postprocess-help.txt` | cargo 入口复用此 postprocess 生成 report/csv | +| cargo starry perf help | PASS | `target/qperf-integration-smoke/help/cargo-starry-perf-help.txt` | 使用临时 `CARGO_HOME` 与测试用 `PKG_CONFIG_PATH` 通过；当前 host 原生环境仍缺 `libudev.pc` | +| cargo starry run help | PASS | `target/qperf-integration-smoke/help/cargo-starry-run-help.txt` | `run` alias 暴露 `--perf`、`--perf-case`、`--perf-workload`、`--perf-focus` 等参数 | +| axbuild check/clippy | PASS | command output | `cargo check -p axbuild`、`cargo clippy -p axbuild -- -D warnings` 通过 | +| cargo CLI parse tests | PASS | command output | `command_parses_perf_*` 与 `command_parses_run_perf_alias` 通过 | +| qperf plugin check | PASS | command output | `cargo check --manifest-path tools/qperf/Cargo.toml` 通过 | +| analyzer flamegraph resolve | PASS | `target/qperf-integration-smoke/analyzer/flamegraph.svg` | 复用已有 blk raw sample 生成 SVG | +| analyzer focused flamegraph | PASS | `target/qperf-integration-smoke/analyzer/flamegraph.virtio.svg` | `--focus 'virtio|VirtQueue'` 输出 159 samples | +| stack.folded symbol 粒度 | PARTIAL | `target/qperf-integration-smoke/analyzer/stack.full.folded` | symbol demangle 可读；调用链仍常短栈 | +| harness perf-postprocess | PASS | `target/qperf-integration-smoke/postprocess/report.json` | 从既有 qperf artifacts 生成 report/csv，参数中包含 `symbol_style/focus/no_truncate` | +| cargo starry perf boot | FAIL | `target/qperf-integration-smoke/logs/cargo-starry-perf-boot.log` | qperf tools、StarryOS build、rootfs 准备均已推进；宿主缺 `qemu-system-riscv64`，未产生 raw samples/report | +| cargo starry perf blk | NOT RUN | N/A | 与 boot 相同的 QEMU host 依赖阻塞，未重复下载/运行 | +| old full harness QEMU run | NOT RUN | N/A | 本轮未再触发 Docker profile，避免重新生成 root-owned `tmp/axbuild`；CLI/help 兼容已验证 | + +本轮真实 boot profile 阻塞原因： + +```text +Error: qperf requires `qemu-system-riscv64` in PATH; install the matching QEMU system emulator or run the Docker-based harness perf-profile entrypoint +``` + +额外环境说明： + +* 当前 host 原生 `pkg-config` 找不到 `libudev.pc`。help/check 验证使用 `/tmp/fake-pkgconfig` 作为只用于编译帮助/测试的替代，不代表生产运行环境；正常环境应安装 `libudev-dev`。 +* 默认 Cargo registry cache 仍有 root-owned cache warning；验证使用 `CARGO_HOME=/tmp/tgoskits-cargo-home` 避免写入用户 cache。 +* 原仓库 `tmp/axbuild/` 存在 root-owned 文件；本轮已通过 `AXBUILD_TMP_DIR` 和 cargo perf 默认 `axbuild-tmp/` 隔离规避。 +* `rust-objcopy` 初始不在 PATH；验证时临时加入 Rust toolchain 的 llvm-tools 路径，随后现有 `starry-kallsyms.sh` 安装了 `cargo-binutils` 与 `gen_ksym` 到 `/tmp/tgoskits-cargo-home/bin`。 + +## 7. 局限性 + +* `cargo starry perf` 代码路径已实现并推进到 QEMU 启动前，但当前 host 缺 `qemu-system-riscv64`，所以 boot/blk profile 未能生成新的 raw samples 和最终 report。 +* qperf 仍是 QEMU TCG plugin 采样，不是 guest PMU。 +* marker window 仍是 timestamp 后处理过滤，不是 runtime pause/resume。 +* stack unwind 仍依赖 frame pointer，不能保证完整 Rust 调用链。 +* counters 仍是 driver-visible 近似值，不是 ring-level 精确统计。 +* host perf/PMU 是可选 host QEMU process 指标。 +* vsock 仍受 `/dev/vhost-vsock` 限制。 + +## 8. 下一步建议 + +1. 在安装 `qemu-system-riscv64`、`libudev-dev`，并保证 `rust-objcopy` 在 PATH 的 host 上重跑 `cargo starry perf --case boot`。 +2. 重跑 blk marker profile，确认 cargo 入口完整生成 `report.json/report.md/hotspots.csv/hotspot_categories.csv/qperf/flamegraph.svg`。 +3. cargo 入口闭环后开始 net RX 去 `copy_within()` A/B。 +4. 开始 net inflight `BTreeMap` 到 fixed array/slab 的 A/B。 +5. 开始 blk pending read / async queue 原型 A/B。 +6. 继续探索 ring-level virtqueue counters 和 runtime pause/resume sampling。 diff --git a/docs/qperf-cargo-starry-integration.md b/docs/qperf-cargo-starry-integration.md new file mode 100644 index 0000000000..3e69cbcbc9 --- /dev/null +++ b/docs/qperf-cargo-starry-integration.md @@ -0,0 +1,170 @@ +# qperf cargo starry 集成指南 + +## 快速开始 + +默认 boot profile： + +```bash +cargo starry perf --case boot +``` + +blk marker profile： + +```bash +cargo starry perf \ + --case blk-read \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --workload 'echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk-read' +``` + +`--qperf-metrics` 只负责把 guest stdout 中的 `QPERF_METRIC key=value` +合入报告；内核或 driver 侧的 `/proc/qperf_metrics` 插桩需要由被测分支单独提供。 + +`cargo starry run --perf` 是 `cargo starry qemu --perf` 的 alias 路径，适合用户按 run 语义启动默认 qperf： + +```bash +cargo starry run --perf --perf-case boot +``` + +如果只是复盘已有结果或在没有 host QEMU 的机器上做报告分析，可以直接阅读已经生成的 +`report.json`、`hotspot_categories.csv` 和 `qperf/stack.folded`。当前仓库中的 blk +瓶颈分析见 `docs/qperf-current-blk-bottleneck-analysis.md`。 + +## 环境依赖 + +`cargo starry perf` 在 host 上直接运行 QEMU，需要： + +* `qemu-system-riscv64` 或对应 arch 的 system QEMU 在 `PATH` 中。 +* Rust `llvm-tools`/`cargo-binutils` 提供 `rust-objcopy`、`rust-nm`。 +* axbuild 依赖的 host 库，例如 `libudev.pc`；Debian/Ubuntu 通常来自 `libudev-dev`。 + +本入口会把 StarryOS build config、generated axconfig 和 managed rootfs 隔离到当前 qperf 输出目录下的 `axbuild-tmp/`。高级用户可以显式设置 `AXBUILD_TMP_DIR=` 复用或重定向这部分临时文件。 + +## 默认值 + +`cargo starry perf` 默认使用： + +| 参数 | 默认值 | +| --- | --- | +| arch | `riscv64` | +| case | `boot` | +| output | `target/qperf//perf//latest/` | +| qperf freq | `99` | +| max depth | `128` | +| mode | `tb` | +| format | `all` | +| top | `80` | +| min percent | `0.3` | +| host time | enabled | +| qperf metrics | disabled unless guest prints `QPERF_METRIC` lines | + +生成完成后会打印： + +```text +qperf report generated: + report: target/qperf//perf/riscv64/latest/report.md + flamegraph: target/qperf//perf/riscv64/latest/qperf/flamegraph.svg + folded stack: target/qperf//perf/riscv64/latest/qperf/stack.folded + json: target/qperf//perf/riscv64/latest/report.json +``` + +## 高级参数 + +常用 qperf 参数： + +```bash +cargo starry perf \ + --case net-wget \ + --freq 199 \ + --max-depth 256 \ + --mode insn \ + --symbol-style full \ + --focus 'virtio|net|memcpy|memmove' \ + --no-truncate +``` + +`cargo starry run --perf` 使用 `--perf-*` 前缀： + +```bash +cargo starry run \ + --perf \ + --perf-case blk-read \ + --perf-workload 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' \ + --perf-start-marker QPERF_BEGIN \ + --perf-stop-marker QPERF_END \ + --perf-qperf-metrics \ + --perf-symbol-style full \ + --perf-focus 'virtio|block' +``` + +当前 `run --perf` 只支持默认 qperf QEMU/rootfs flow，以及 `--arch`、`--debug` 这类轻量 build override。带 `--qemu-config`、`--rootfs`、`--config`、`--target`、`--smp` 的 perf run 仍应使用 plain `cargo starry qemu` 或后续扩展。 + +## 输出文件 + +| 文件 | 说明 | +| --- | --- | +| `report.json` | 机器可读报告 | +| `report.md` | 可直接阅读/粘贴的 Markdown 报告 | +| `hotspots.csv` | symbol hotspot | +| `hotspot_categories.csv` | 工程归因类别 | +| `qperf/stack.folded` | 完整 folded stack | +| `qperf/flamegraph.svg` | 默认完整火焰图 | +| `qperf/flamegraph.workload.svg` | marker workload window 火焰图 | +| `qperf/flamegraph.boot.svg` | boot 阶段火焰图 | +| `qperf/flamegraph.post.svg` | post-window 火焰图 | +| `qperf/flamegraph.focus.svg` | `--focus` 过滤后的火焰图 | +| `qperf/summary.txt` | qperf run 摘要 | + +## 用 qperf 做 blk 瓶颈初筛 + +推荐先跑 marker + metrics workload： + +```bash +cargo starry perf \ + --case blk-read \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' +``` + +读报告时优先看三组字段： + +| 字段 | 用途 | +| --- | --- | +| `window` | 确认 boot/post-window 样本是否被排除 | +| `hotspot_categories.csv` | 看 copy、virtqueue、allocator、scheduler 等工程类别占比 | +| `workload_metrics.values` | 看 `virtqueue_add_notify_wait_pop_count`、notify/kick、blk read bytes/requests 等 driver-visible counters | + +当前已有 blk profile 显示，`virtqueue_add_notify_wait_pop` 和 +`virtio_notify_kick` 都在 workload window 内占到约 25% 级别，且 +`virtio_blk_read_bytes / virtio_blk_read_requests` 约为 4 KiB。这个结果指向 +“大量同步 4 KiB 级别 virtqueue 请求，queue depth 没有被持续利用”的 blk +优化方向。完整证据和限制见 `docs/qperf-current-blk-bottleneck-analysis.md`。 + +## A/B compare + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/qperf/blk-read/perf/riscv64/latest/report.json \ + --candidate target/qperf/blk-read-patched/perf/riscv64/latest/report.json \ + --name blk-read-ab \ + --output-dir target/qperf/compare +``` + +## 网络与 vsock 注意事项 + +在 Docker/WSL 下，guest 的 `10.0.2.2` 通常指向 QEMU slirp 所在网络命名空间，不一定能访问 WSL host 上启动的 HTTP server。net profile 建议在同一个 Docker 容器内启动 HTTP server，或明确使用 host 网络。 + +vsock 需要 host 具备 `/dev/vhost-vsock`。如果不存在，不应输出伪造吞吐或 counter。 + +## 当前局限 + +* qperf 仍是 QEMU TCG plugin 采样，不是 guest PMU。 +* marker window 仍是 raw timestamp 后处理过滤，不是 runtime pause/resume。 +* stack unwind 依赖 frame pointer 和可解析 DWARF；inline、tail call、汇编 trampoline 可能断栈。 +* virtio counters 是 driver-visible 近似值，不是 ring-level 精确硬件事件。 +* user symbol 解析当前只在符号存在于 kernel ELF 时可见。 diff --git a/docs/qperf-flamegraph-guide.md b/docs/qperf-flamegraph-guide.md new file mode 100644 index 0000000000..89345bc6f9 --- /dev/null +++ b/docs/qperf-flamegraph-guide.md @@ -0,0 +1,182 @@ +# qperf 火焰图指南 + +## 快速生成 + +默认 profile 使用 leaf 模式，开销低，但调用栈通常只有一层： + +```bash +cargo starry perf --case boot --symbol-style full +``` + +需要纵向展开的深调用栈时，使用 `--full-stack`： + +```bash +cargo starry perf \ + --case blk-full-stack \ + --full-stack \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk' +``` + +`--full-stack` 会启用 frame pointer callchain，并在 kernel 构建中加入： + +```text +-Cdebuginfo=2 +-Cstrip=none +-Cforce-frame-pointers=yes +``` + +因此它比默认 profile 慢，也会触发更多构建工作；只在需要深栈火焰图时开启。 + +## callchain 模式 + +| 模式 | 用法 | 说明 | +| --- | --- | --- | +| `leaf` | 默认 | 只记录采样 PC，适合粗略热点和旧命令兼容。 | +| `fp` | `--perf-callchain fp` 或 `--full-stack` | 读取 RISC-V `sp/fp`，按 frame pointer 链恢复 kernel 调用栈。 | +| `logical` | 当前不可用 | 预留人工插桩逻辑栈模式。本轮没有实现，不会伪装成真实 callchain。 | + +如果只传 `--perf-callchain fp`，还应配合： + +```bash +--perf-debuginfo --perf-force-frame-pointers +``` + +实际使用中推荐直接传 `--full-stack`。 + +## 读哪些文件 + +| 文件 | 说明 | +| --- | --- | +| `qperf/flamegraph.svg` | 完整 profile 火焰图。 | +| `qperf/flamegraph.workload.svg` | marker window 内样本火焰图。 | +| `qperf/flamegraph.boot.svg` | start marker 前样本火焰图。 | +| `qperf/flamegraph.post.svg` | stop marker 后样本火焰图，可能为空。 | +| `qperf/flamegraph.focus.svg` | `--focus` regex 命中的 focused 火焰图。 | +| `qperf/stack.folded` | folded stack 原始输入，默认保留完整 demangled Rust symbol。 | +| `qperf/stack-depth-summary.csv` | raw callchain 地址深度分布。 | +| `hotspots.csv` | 函数级热点聚合。 | +| `hotspot_categories.csv` | 工程类别 inclusive stack 聚合。 | +| `report.json` | 机器可读报告，包含 `callchain` 与 `resolve_stats`。 | + +检查火焰图是否真的有深栈： + +```bash +awk -F';' '{print NF}' target/.../qperf/stack.folded | sort -n | uniq -c +cat target/.../qperf/stack-depth-summary.csv +``` + +如果大部分 `NF=1`，说明当前 folded stack 仍是 leaf-only；应确认是否开启 `--full-stack`，以及 kernel 是否用 frame pointer 构建。 + +## symbol style + +| style | 用途 | +| --- | --- | +| `full` | 保留完整 Rust demangled path，适合归因和搜索。 | +| `module` | 保留 crate 与尾部模块/函数，适合 SVG 可读性。 | +| `short` | 只看函数尾名，适合粗略热点。 | + +SVG 因空间限制可能截断长 frame；需要确认完整 symbol 时看 `stack.folded`。 + +## marker/window + +推荐所有 workload profile 使用 marker，避免 boot 样本污染： + +```bash +cargo starry perf \ + --case blk-read \ + --full-stack \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk-read' +``` + +`report.json.window` 会记录： + +* `start_time` +* `stop_time` +* `duration_sec` +* `boot_samples_excluded` +* `post_window_samples_excluded` +* `warnings` + +当前 window 过滤是 postprocess 级别过滤，不是 QEMU plugin runtime pause/resume。 + +## 聚焦 virtio/block 路径 + +```bash +cargo starry perf \ + --case blk-virtio \ + --full-stack \ + --qperf-metrics \ + --focus 'virtio|VirtQueue|block|memcpy|memmove' \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk' +``` + +典型深栈应能看到类似路径： + +```text +starry_kernel::syscall::fs::io::sys_read + -> ax_fs_ng / rsext4 + -> ax_driver::block::binding::Block::read_blocks_wait + -> rd_block::CmdQueue::read_blocks_blocking + -> ax_driver::virtio::block::BlockQueue::submit_request + -> virtio_drivers::queue::VirtQueue::add_notify_wait_pop +``` + +## 聚焦 net 路径 + +先启动 host HTTP server： + +```bash +python3 -m http.server 8000 --bind 0.0.0.0 +``` + +另一个终端运行： + +```bash +cargo starry perf \ + --case net-full-stack \ + --full-stack \ + --qperf-metrics \ + --timeout 300 \ + --workload-timeout 240 \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:net; wget -O /dev/null http://10.0.2.2:8000/tmp/axbuild/rootfs/rootfs-riscv64-alpine.img.tar.xz; cat /proc/qperf_metrics; echo QPERF_END:net' +``` + +典型深栈应能看到： + +```text +starry_kernel::syscall::fs::io::sys_readv + -> ax_net_ng::SocketOps::recv + -> ax_net_ng::poll_interfaces + -> RdNetDriver::prefetch_rx_packets + -> rd_net::RxQueue + -> compiler_builtins::mem::memcpy / memmove +``` + +## 当前验证数据 + +本轮验证产物位于 `target/qperf-callchain-validation/`： + +| case | callchain | 多帧样本 | raw max depth | folded symbol depth | +| --- | --- | ---: | ---: | ---: | +| blk leaf | `leaf` | 0 / 577 | 1 | 1 | +| blk full-stack | `fp` | 578 / 579 | 18 | 最高 72 | +| net full-stack | `fp` | 652 / 661 | 17 | 最高 78 | + +详细报告见 `docs/qperf-callchain-validation-report.md`。 + +## 技术边界 + +* qperf 仍是 QEMU TCG plugin 采样，不是 guest PMU。 +* `fp` 模式依赖 frame pointer；没有 `-Cforce-frame-pointers=yes` 时无法保证深栈。 +* 当前只解析 kernel ELF，用户态符号尚未纳入。 +* trap、异常入口、任务切换、汇编 trampoline 可能截断调用链。 +* inline frame 会让 folded symbol 层数大于 raw FP 地址层数；两者都是真实信息，但含义不同。 +* `hotspot_categories.csv` 是 inclusive stack 分类，不是互斥 CPU 时间分解。 diff --git a/docs/qperf-marker-and-metrics-usage.md b/docs/qperf-marker-and-metrics-usage.md new file mode 100644 index 0000000000..5b850cc0ae --- /dev/null +++ b/docs/qperf-marker-and-metrics-usage.md @@ -0,0 +1,158 @@ +# qperf Marker And Metrics Usage + +`cargo starry perf` is now the preferred entrypoint for local qperf runs. The +lower-level harness commands below remain supported for Docker-wrapped syscall +harness workflows and compatibility. + +```bash +cargo starry perf \ + --case blk-read \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' +``` + +See also `docs/qperf-cargo-starry-integration.md` and +`docs/qperf-flamegraph-guide.md`. + +## Basic Marker Run + +Use explicit guest stdout markers around the workload: + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --timeout 60 \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 30 \ + --shell-init-cmd 'echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; echo QPERF_END:blk-read' +``` + +The report window is written to `report.json.window` and `qperf/window.json`. + +Important fields: + +- `window.start_marker` +- `window.stop_marker` +- `window.start_time` +- `window.stop_time` +- `window.duration_sec` +- `window.truncated_by_timeout` +- `window.boot_samples_excluded` +- `window.warnings` + +If the start marker is missing, the report includes a warning because boot samples may still be present. If the stop marker is missing, the window extends until QEMU exits or times out. + +## Virtio Counter Run + +The tools-side parser can merge any `QPERF_METRIC key=value` line printed by the +guest into `report.json.workload_metrics.values`. If the profiled StarryOS +branch provides `/proc/qperf_metrics`, enable parsing with `--qperf-metrics`, +reset before the workload, and print `/proc/qperf_metrics` before the stop +marker: + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --timeout 60 \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 30 \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' +``` + +For net: + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --timeout 90 \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:net-wget; wget -O /dev/null http://10.0.2.2:8000/tmp/axbuild/rootfs/rootfs-riscv64-alpine.img.tar.xz; cat /proc/qperf_metrics; echo QPERF_END:net-wget' +``` + +When this command is run through the default Docker wrapper, the HTTP server for +`10.0.2.2:8000` must be inside the same container namespace as QEMU. One usable +pattern is to start `python3 -m http.server 8000 --bind 0.0.0.0` in the wrapper +before invoking `harness.py --no-docker`. + +The parser merges `QPERF_METRIC key=value` fields into `report.json.workload_metrics.values`. +This tools-only integration does not create `/proc/qperf_metrics` by itself; +that procfs export is a separate kernel/driver instrumentation concern. + +## Counter Interpretation + +When a profiled branch exports counters through `/proc/qperf_metrics`, those +counters are driver-visible observations. They are useful for A/B validation, +but they should not be described as exact virtqueue ring-level accounting. + +Important blk counters: + +- `virtqueue_add_notify_wait_pop_count`: synchronous virtqueue submit/notify/wait/pop path count. +- `virtqueue_add_count`: driver-visible virtqueue add count. +- `virtio_notify_kick_count`: driver-visible notify/kick count. +- `virtqueue_pop_complete_count`: driver-visible completion pop count. +- `virtqueue_depth_max` and `virtqueue_depth_hist_*`: approximate queue depth observation. +- `virtio_blk_read_requests` and `virtio_blk_read_bytes`: blk read request count and bytes recorded by the driver. + +One existing marker-aware blk profile at +`target/qperf-validation/blk/perf/riscv64/latest/report.json` reported: + +| metric | value | +| --- | ---: | +| `dd` bytes | 53,601,104 | +| `dd` elapsed | 5.794463 s | +| `virtqueue_add_notify_wait_pop_count` | 13,780 | +| `virtio_notify_kick_count` | 13,847 | +| `virtio_blk_read_requests` | 13,478 | +| `virtio_blk_read_bytes` | 55,195,136 | +| average blk read request size | 4,095.20 bytes | + +This is a useful bottleneck signal: even when the guest command uses +`bs=64k`, the driver-visible blk request size is still about 4 KiB and the +number of notify/kick events is close to the number of virtqueue adds. See +`docs/qperf-current-blk-bottleneck-analysis.md` for the full analysis. + +## Host Perf + +Host perf is opt-in: + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --host-time \ + --host-perf \ + --host-perf-events task-clock,cycles,instructions,cache-references,cache-misses +``` + +These counters measure the host QEMU process. They are not guest PMU counters. + +## A/B Compare + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/starry-syscall-harness/perf/riscv64/baseline/report.json \ + --candidate target/starry-syscall-harness/perf/riscv64/candidate/report.json \ + --name blk-read-ab +``` + +The comparison output is under: + +```text +target/starry-syscall-harness/perf-compare/blk-read-ab/ +``` + +`compare.md` gives an automatic conclusion: `明显改善`, `基本无变化`, `退化`, or `数据不足`. + +## Limitations + +- Runtime qperf plugin enable/disable is not implemented; filtering is done by sample timestamps during analyzer postprocess. +- Driver-visible queue depth and notify/kick counters are approximate. Exact ring-level accounting requires adding counters inside `virtio-drivers`. +- Place `cat /proc/qperf_metrics` before the stop marker. The harness asks QEMU to quit once the stop marker is observed. +- If `/dev/vhost-vsock` is missing on the host, vsock experiments should record the environment blocker and must not fabricate vsock throughput or counters. diff --git a/docs/qperf-tooling-improvement-report.md b/docs/qperf-tooling-improvement-report.md new file mode 100644 index 0000000000..a07419e62b --- /dev/null +++ b/docs/qperf-tooling-improvement-report.md @@ -0,0 +1,331 @@ +# qperf Tooling Improvement Report + +## 当前问题复盘 + +原 qperf 更接近“从 QEMU 启动到退出的栈采样器”。对 virtio-blk/net/vsock 做性能归因时有三个直接问题： + +- 采样窗口默认覆盖 boot，PCI probe、调度、allocator、rootfs 初始化会混入数据面结论。 +- 输出主要是 folded stack、火焰图和符号热点，不能直接回答 queue depth、notify/kick、copy bytes、inflight 操作次数等工程问题。 +- 优化前后需要人工翻多个报告，缺少字段级 delta、百分比变化和数据不足提示。 + +## 改造目标 + +本轮改造的目标是形成一个最小可闭环的实验工具： + +- 用 guest stdout marker 定义 workload 窗口，默认避免 boot 污染。 +- 保留原有 qperf 输出，同时增加类别归因、workload metrics、归一化指标。 +- 用 feature-gated 轻量 counter 记录 virtio-blk/net 的关键路径事件。 +- 增加 A/B compare，支撑优化验证。 +- 对 vsock 环境阻塞显式记录，不伪造吞吐或 counter。 + +## 实现方案 + +### marker/window + +`cargo xtask starry perf` 与 `harness.py perf-profile` 新增： + +- `--start-marker TEXT` +- `--stop-marker TEXT` +- `--workload-timeout SECONDS` +- `--qperf-metrics` + +qperf plugin raw record 升级为带 `elapsed_ns` 的 v2 格式。`qperf-analyzer resolve` 新增 `--start-sec`、`--stop-sec`、`--stats`，按 marker 时间在 postprocess 阶段过滤 folded stack 和 flamegraph。旧 raw 格式仍可解析，但不能做时间窗口过滤。 + +marker 模式下，harness 会在 shell prompt 出现后注入 workload，并先关闭串口回显，避免 shell 把整行命令回显出来导致 `QPERF_END` 被提前匹配。stop marker 出现后，harness 优先通过 QMP `quit` 停 QEMU，失败再退回 SIGINT。 + +### 分类聚合 + +报告新增 `hotspot_categories.csv`，并在 `report.json.hotspots.category_totals` 和 `report.md` 写入 inclusive category 聚合。当前类别包括： + +- `virtqueue_add_notify_wait_pop` +- `virtqueue_add` +- `virtqueue_pop_complete` +- `virtio_notify_kick` +- `memcpy` +- `memmove` +- `allocator` +- `scheduler_wait_preempt` +- `lock_mutex_wait` +- `pci_probe_transport` +- `net_inflight_btree` +- `block_io_path` +- `net_rx_tx_path` +- `vsock_tx_rx_path` + +类别是工程归因视角，和符号热点并列展示；一个栈可以同时计入 subsystem 和 bottleneck 类别。 + +### workload metrics + +harness 解析 guest stdout： + +- `dd`：bytes、seconds、reported MB/s、派生 B/s。 +- `wget`：saved 状态、BusyBox 进度条里的大小；若 wget 不输出耗时，则使用 marker window duration 作为 `elapsed_source=marker_window`。 +- `QPERF_METRIC key=value`：合入 `report.json.workload_metrics.values`。 + +新增归一化字段： + +- `guest_instructions_per_MB` +- `guest_blocks_per_MB` +- `host_elapsed_sec_per_MB` +- `samples_per_MB` +- `category_samples_per_MB` + +本轮示例未启用 `--host-perf`，报告中明确记录 `未启用 host perf`。 + +### virtio counters + +`ax-driver` 新增默认关闭的 `qperf-metrics` feature。启用后通过 `AtomicU64` 记录 driver-visible counter，并由 StarryOS `/proc/qperf_metrics` 导出 `QPERF_METRIC`： + +- virtqueue add/notify/pop/add_notify_wait_pop 近似计数。 +- driver 可见 inflight depth max 和 histogram。 +- blk read/write request count 和 bytes。 +- net RX/TX packet count 和 bytes。 +- net RX `copy_within` count 和 bytes。 +- net TX staging copy count 和 bytes。 +- net inflight map insert/remove/get count。 + +这些 counter 是 driver glue 层视角的近似值。精确 descriptor-ring depth、精确 notify/kick 和 `VirtQueue::add_notify_wait_pop()` 内部事件仍需要在 `virtio-drivers` crate 内增加 instrumentation。 + +### A/B compare + +新增： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline \ + --candidate \ + --name +``` + +输出： + +- `compare.json` +- `compare.md` +- `compare.csv` + +对比字段包括 workload throughput/elapsed、guest executed instructions/blocks、host elapsed/user/sys、hotspot categories、virtio counters、copy bytes、notify/kick count、queue depth max/histogram。缺失字段显示 `N/A`。 + +已做 smoke test： + +```text +target/qperf-tooling-experiments/blk/compare-self/perf-compare/blk-self-smoke/compare.md +``` + +结论为 `基本无变化`，这是同一份 blk report 自比较的预期结果。 + +## 新增 JSON 字段说明 + +`report.json.window`： + +- `start_marker` / `stop_marker`：marker 文本。 +- `start_time` / `stop_time`：相对 QEMU 启动的秒数。 +- `duration_sec`：workload 窗口时长。 +- `workload_timeout`：窗口超时配置。 +- `truncated_by_timeout`：是否由 workload timeout 截断。 +- `boot_samples_excluded`：过滤掉的 start marker 之前样本数。 +- `post_window_samples_excluded`：过滤掉的 stop marker 之后样本数。 +- `stop_method`：如 `qmp_quit`。 +- `warnings`：marker 缺失、旧 raw 格式等风险。 + +`report.json.workload_metrics`： + +- `dd[]` +- `wget[]` +- `custom[]` +- `values` +- `raw_metric_lines` + +`report.json.normalized_metrics`： + +- `workload_bytes` +- `workload_elapsed_seconds` +- `samples_per_MB` +- `host_elapsed_sec_per_MB` +- `guest_instructions_per_MB` +- `guest_blocks_per_MB` +- `category_samples_per_MB` + +## 示例实验结果 + +实验环境： + +- arch: `riscv64` +- qperf freq: `99` +- mode: `tb` +- `--host-time` enabled +- `--host-perf` disabled +- `--qperf-metrics` enabled +- net 用例在同一个 Docker 容器内启动临时 `python3 -m http.server 8000`，确保 guest 的 `10.0.2.2:8000` 可达。 + +### blk focused workload + +命令： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --timeout 90 \ + --format folded \ + --top 20 \ + --host-time \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --output-dir target/qperf-tooling-experiments/blk \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' +``` + +产物： + +```text +target/qperf-tooling-experiments/blk/perf/riscv64/latest/report.json +``` + +实际结果： + +- samples: `589` +- window: `1.58549195 -> 7.539382377`, duration `5.953890427s` +- boot samples excluded: `156` +- post-window samples excluded: `496` +- dd: `53601104 bytes`, `5.805581s`, `9232685.58 B/s` +- host elapsed: `12.552265s` +- samples_per_MB: `10.98858` +- host_elapsed_sec_per_MB: `0.234179` + +主要类别： + +| Category | Samples | Percent | +|---|---:|---:| +| `memcpy` | 166 | 28.18% | +| `virtio_notify_kick` | 145 | 24.62% | +| `virtqueue_add_notify_wait_pop` | 144 | 24.45% | +| `block_io_path` | 115 | 19.52% | +| `allocator` | 89 | 15.11% | + +关键 counter： + +| Counter | Value | +|---|---:| +| `virtqueue_add_notify_wait_pop_count` | 13780 | +| `virtqueue_add_count` | 13847 | +| `virtio_notify_kick_count` | 13847 | +| `virtqueue_pop_complete_count` | 13783 | +| `virtqueue_depth_max` | 63 | +| `virtio_blk_read_requests` | 13478 | +| `virtio_blk_read_bytes` | 55195136 | +| `virtio_blk_write_requests` | 302 | +| `virtio_blk_write_bytes` | 1236992 | + +结论：blk 数据面窗口里 `add_notify_wait_pop` 和 notify/kick 占比明确可见，且 counter 显示 read request 数与同步等待次数基本同量级，支持继续验证异步化、批处理和更高 queue depth 的优化方向。 + +### net focused workload + +命令核心： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --timeout 120 \ + --format folded \ + --top 20 \ + --host-time \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 60 \ + --output-dir target/qperf-tooling-experiments/net \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:net-wget; wget -O /dev/null http://10.0.2.2:8000/tmp/axbuild/rootfs/rootfs-riscv64-alpine.img.tar.xz; cat /proc/qperf_metrics; echo QPERF_END:net-wget' +``` + +产物： + +```text +target/qperf-tooling-experiments/net/perf/riscv64/latest/report.json +``` + +实际结果： + +- samples: `719` +- window: `1.566331117 -> 8.825886896`, duration `7.259555779s` +- boot samples excluded: `154` +- post-window samples excluded: `494` +- wget: BusyBox progress `60.6M`, parsed as `63543705 bytes` +- wget elapsed source: `marker_window` +- wget throughput: `8753112.03 B/s` +- host elapsed: `13.836669s` +- samples_per_MB: `11.315047` +- host_elapsed_sec_per_MB: `0.21775` + +主要类别： + +| Category | Samples | Percent | +|---|---:|---:| +| `memcpy` | 231 | 32.13% | +| `net_rx_tx_path` | 169 | 23.50% | +| `allocator` | 117 | 16.27% | +| `memmove` | 53 | 7.37% | +| `scheduler_wait_preempt` | 24 | 3.34% | + +关键 counter： + +| Counter | Value | +|---|---:| +| `virtqueue_add_notify_wait_pop_count` | 605 | +| `virtqueue_add_count` | 47289 | +| `virtio_notify_kick_count` | 47289 | +| `virtqueue_pop_complete_count` | 47225 | +| `virtqueue_depth_max` | 63 | +| `virtio_net_rx_packets` | 44141 | +| `virtio_net_rx_bytes` | 65937102 | +| `virtio_net_rx_copy_within_bytes` | 65937102 | +| `virtio_net_tx_staging_copy_bytes` | 149442 | +| `virtio_net_inflight_insert_count` | 46684 | +| `virtio_net_inflight_remove_count` | 46620 | +| `virtio_net_inflight_get_count` | 46620 | + +结论：net 数据面里的 copy 成本已被同时体现在符号热点、类别聚合和 counter 中。RX `copy_within` bytes 与 RX bytes 同量级，说明 RX 路径每包仍有完整搬移；TX staging copy 相对下载流量较小。inflight map 操作次数和包数同量级，后续应针对该结构做替换或减少访问频率的 A/B 验证。 + +## 新旧报告对比 + +旧报告只能回答“哪些 guest 函数/栈采样最多”，且默认混入 boot-to-exit 样本。新报告可以直接看到： + +- marker window 起止时间、时长、boot/post-window 排除样本数。 +- 符号热点与工程类别热点分离展示。 +- workload bytes、elapsed、throughput 和 per-MB 归一化指标。 +- virtio counter 与 copy bytes。 +- host perf 未启用时的显式说明。 +- A/B compare 的 delta、百分比变化和 `N/A` 缺失字段。 + +本轮没有生成“旧工具同 workload”的历史 baseline，因此没有伪造旧版数字。已有 `blk-self-smoke` compare 只用于验证 compare 工具输出路径和缺失字段处理。 + +## 局限性 + +- qperf plugin 仍未支持运行时暂停/恢复；当前是 timestamped raw sample + analyzer postprocess 过滤。 +- driver-visible queue depth/notify/kick 是近似 counter，不等价于 virtio ring 内部精确事件。 +- `guest_instructions_per_MB` 和 `guest_blocks_per_MB` 当前为 `N/A`，需要 qperf summary 稳定导出 executed instruction/block 字段后才能归一化。 +- net wget 的 BusyBox 输出没有真实下载耗时，本轮用 marker window duration 派生 elapsed/throughput，并在 JSON 中记录 `elapsed_source=marker_window`。 +- host perf 本轮未启用；报告只合入 host wall/user/sys time。 +- 当前宿主机没有 `/dev/vhost-vsock`：`ls /dev/vhost-vsock` 返回 `No such file or directory`。因此本轮没有 vsock 吞吐数据，也没有编造 vsock counter。 +- `target/qperf-tooling-experiments` 曾由 Docker root 创建，直接写顶层 compare 目录会遇到权限问题；后续可统一在 wrapper 里 chown 输出根目录。 + +## 后续优化建议 + +virtio-blk： + +- 将同步 `add_notify_wait_pop` 路径改为可批处理或异步 completion，先用 `virtqueue_add_notify_wait_pop_count`、throughput 和 `block_io_path` category 做 A/B。 +- 对连续 read 请求做合并或更大块提交，观察 request count、notify/kick count 是否下降。 +- 在 `virtio-drivers` 内加入精确 ring depth 和 kick counter，校准 driver-visible 近似值。 + +virtio-net： + +- 优先减少 RX `copy_within`，目标是让 `virtio_net_rx_copy_within_bytes / virtio_net_rx_bytes` 明显下降。 +- 减少 TX staging Vec copy，观察 `virtio_net_tx_staging_copy_bytes` 和 `memcpy` category。 +- 替换或减少 inflight `BTreeMap` 操作，使用 counter 和 `net_inflight_btree` category 做验证。 +- 将 RX/TX queue lock 拆分或缩短锁内 copy，观察 `net_rx_tx_path`、allocator、scheduler 类别变化。 + +virtio-vsock： + +- 先补齐 `/dev/vhost-vsock` 环境和可重复 workload。 +- 环境不可用时，report 应保留 blocker 字段或 stdout marker 说明，不输出吞吐。 +- 可用后按 net 的方式增加 vsock TX/RX bytes、packet、copy、queue counter，并纳入 compare。 diff --git a/docs/qperf-tooling-redesign.md b/docs/qperf-tooling-redesign.md new file mode 100644 index 0000000000..da0b01a6cd --- /dev/null +++ b/docs/qperf-tooling-redesign.md @@ -0,0 +1,117 @@ +# qperf Tooling Redesign + +## Goals + +This redesign turns qperf from a boot-to-exit stack sampler into a workload-oriented experiment tool for virtio-blk, virtio-net, and virtio-vsock attribution. + +The main changes are: + +- workload windows driven by guest stdout markers; +- timestamped qperf samples and analyzer-side time filtering; +- hotspot category aggregation in addition to symbol hotspots; +- workload stdout metric parsing for `dd`, `wget`, and `QPERF_METRIC`; +- feature-gated virtio counters exported through `/proc/qperf_metrics`; +- report-level A/B comparison for baseline and candidate runs. + +## Sampling Window + +`cargo xtask starry perf` and `harness.py perf-profile` accept: + +- `--start-marker TEXT` +- `--stop-marker TEXT` +- `--workload-timeout SECONDS` + +When a start marker is observed in guest stdout, the host records elapsed time since QEMU launch. When a stop marker is observed, qperf asks QEMU to quit through QMP, falling back to SIGINT if QMP is unavailable. + +For shell-injected workloads, the monitor disables shell echo before sending the command so marker matching is driven by workload output rather than by the echoed command line. + +The qperf plugin now writes raw records as format version 2: + +- `elapsed_ns` +- stack IP trace + +`qperf-analyzer resolve` accepts `--start-sec`, `--stop-sec`, and `--stats`. The generated folded stack and flamegraph are filtered to the marker window when timestamps are available. Older raw files are still accepted, but elapsed-time filtering cannot be applied to format version 1 samples. + +## Attribution Categories + +The harness parses `qperf/stack.folded` and writes inclusive category totals to: + +- `hotspot_categories.csv` +- `report.json.hotspots.category_totals` +- `report.md` + +The current category set is: + +- `virtqueue_add_notify_wait_pop` +- `virtqueue_add` +- `virtqueue_pop_complete` +- `virtio_notify_kick` +- `memcpy` +- `memmove` +- `allocator` +- `scheduler_wait_preempt` +- `lock_mutex_wait` +- `pci_probe_transport` +- `net_inflight_btree` +- `block_io_path` +- `net_rx_tx_path` +- `vsock_tx_rx_path` + +Categories are inclusive and non-exclusive: one stack can contribute to both a subsystem category, such as `net_rx_tx_path`, and a bottleneck category, such as `memmove`. + +## Workload Metrics + +The harness parses guest stdout for: + +- `dd` byte count, elapsed seconds, and throughput; +- `wget` length/saved byte count and elapsed seconds when visible; +- custom `QPERF_METRIC key=value` fields. + +Parsed values are stored in: + +- `report.json.workload_metrics` +- `report.json.normalized_metrics` + +Normalized fields include: + +- `guest_instructions_per_MB` +- `guest_blocks_per_MB` +- `host_elapsed_sec_per_MB` +- `samples_per_MB` +- `category_samples_per_MB` + +Host perf stat output is included only when `--host-perf` is enabled. Otherwise the report explicitly records `未启用 host perf`. + +## Virtio Counters + +The `qperf-metrics` feature is off by default. When enabled, `ax-driver` records lightweight `AtomicU64` counters in the virtio glue layer: + +- blk read/write request count and bytes; +- net RX/TX packet count and bytes; +- net RX `copy_within` count and bytes; +- net TX staging copy count and bytes; +- inflight map insert/remove/get count; +- approximate virtqueue add/notify/pop counts from driver submit/reclaim points; +- approximate queue depth max and histogram from driver-visible inflight depth. + +The counters are exported by StarryOS at `/proc/qperf_metrics` as `QPERF_METRIC` lines. Writing `reset` clears the counters. + +These counters are intentionally described as driver-visible approximations. Exact descriptor-ring depth, exact notify/kick count, and `VirtQueue::add_notify_wait_pop()` internals require instrumentation inside the `virtio-drivers` crate. + +## A/B Compare + +Use: + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/starry-syscall-harness/perf/riscv64/baseline \ + --candidate target/starry-syscall-harness/perf/riscv64/candidate +``` + +Inputs can be a `report.json`, a profile directory, a qperf directory, or a folded stack file. Outputs are: + +- `compare.json` +- `compare.md` +- `compare.csv` + +The comparison includes workload throughput/elapsed time, guest executed instructions/blocks, host time/perf metrics, hotspot categories, virtio counters, copy bytes, notify/kick count, and queue depth fields when present. Missing fields are rendered as `N/A` instead of failing. diff --git a/docs/qperf-tooling-validation-report.md b/docs/qperf-tooling-validation-report.md new file mode 100644 index 0000000000..e956bc2bc2 --- /dev/null +++ b/docs/qperf-tooling-validation-report.md @@ -0,0 +1,262 @@ +# qperf 工具改造验收报告 + +## 1. 验收目标 + +本轮验收验证 qperf 工具改造是否已经从“启动即采样的火焰图工具”升级为可支撑 virtio-blk、virtio-net、virtio-vsock 性能归因和优化 A/B 验证的实验工具。重点回答： + +* 是否解决 boot 阶段样本污染 workload 数据面的问题。 +* 是否具备 marker 驱动的 workload window。 +* 是否具备工程分类热点，而不只是 symbol hotspot。 +* 是否具备 virtio-aware counters，并能进入最终 report。 +* 是否具备 A/B compare 输出。 +* 是否保持旧 perf-profile 命令兼容。 +* 是否足以支撑下一轮 virtio 优化验证。 + +## 2. 验收环境 + +| 项目 | 值 | +| --- | --- | +| 仓库 commit | `6e748d6b7a5b3a8e90e2cba3b030ea0ca9c3e617` | +| 分支 | `fix/starry-syscall-harness` | +| git status | 工作区非干净，包含本轮 qperf 改造文件和若干既有未跟踪文档；本报告未覆盖已有实验结果 | +| Host kernel | `Linux LAPTOP-SAOPKIGH 5.15.167.4-microsoft-standard-WSL2 x86_64` | +| CPU | Intel Core i7-14650HX, 24 vCPU, WSL2 | +| Docker image | `ghcr.io/rcore-os/tgoskits-container:latest`, image id `sha256:b7c4600e825dcb474d1f6a6bc51b8e6616ada23a24d048fc45522a58f76eb162` | +| Guest arch | `riscv64` | +| QEMU | `qemu-system-riscv64`, `virt` machine, 512 MiB, virtio-blk-pci, virtio-net-pci user net, qperf plugin, QMP unix socket | +| qperf 参数 | marker runs 使用 `--host-time --qperf-metrics --start-marker QPERF_BEGIN --stop-marker QPERF_END --workload-timeout 45` | +| qperf-metrics | blk/net marker 用例启用；兼容性旧命令未启用 | +| host perf | 未启用；报告中显示 `未启用 host perf` | + +构建检查： + +* `python3 -m py_compile tools/starry-syscall-harness/harness.py`：PASS。 +* `cargo clippy -p ax-driver --no-default-features --features 'plat-dyn,virtio-blk,virtio-net,virtio-socket,qperf-metrics' -- -D warnings`：PASS。 +* `cargo clippy -p ax-driver --no-default-features --features 'plat-dyn,virtio-blk,virtio-net,virtio-socket' -- -D warnings`：PASS。 + +## 3. 验收矩阵 + +| 模块 | 验收项 | 结果 | 证据文件 | 备注 | +| --- | --- | --- | --- | --- | +| harness/window | start/stop marker | PASS | `target/qperf-validation/blk/perf/riscv64/latest/report.json` | window start/stop/duration 已记录 | +| harness/window | boot/post-window 样本排除 | PASS | `target/qperf-validation/blk/perf/riscv64/latest/report.json` | blk boot 排除 164，post-window 排除 492 | +| harness/window | marker missing warning | PASS | `target/qperf-validation/missing-stop/perf/riscv64/latest/report.json` | 超时截断并记录 warning | +| qperf/report | required report artifacts | PASS | `target/qperf-validation/blk/perf/riscv64/latest/` | report/json/md、csv、folded、flamegraph、stdout/stderr 存在 | +| qperf/report | plugin summary / guest instr | PARTIAL | `target/qperf-validation/blk/perf/riscv64/latest/report.json` | blk 缺少 `qperf/qperf.summary.txt`，guest instr/blocks per MB 为 N/A | +| qperf/report | hotspot_categories.csv | PASS | `target/qperf-validation/blk/perf/riscv64/latest/hotspot_categories.csv` | 分类非空，包含 memcpy、virtqueue、block path 等 | +| qperf/report | dd parser | PASS | `target/qperf-validation/blk/perf/riscv64/latest/report.json` | 解析 53,601,104 bytes、5.794463s | +| qperf/report | wget parser | PASS | `target/qperf-validation/net-container/perf/riscv64/latest/report.json` | container 内 HTTP server 用例解析成功 | +| qperf/report | 用户给定 net 命令 | FAIL | `target/qperf-validation/net/perf/riscv64/latest/profile.stdout` | Docker/WSL 拓扑下 `10.0.2.2:8000` connection refused | +| virtio counters | feature 默认关闭 | PASS | `drivers/ax-driver/Cargo.toml`，clippy 输出 | 默认 feature 未强制开启 instrumentation | +| virtio counters | blk counters | PASS | `target/qperf-validation/blk/perf/riscv64/latest/report.json` | blk read bytes/request、virtqueue、notify/kick 计数进入 report | +| virtio counters | net counters | PASS | `target/qperf-validation/net-container/perf/riscv64/latest/report.json` | RX/TX bytes、copy bytes、inflight 操作进入 report | +| virtio counters | reset counters | PARTIAL | marker workload shell 命令与 `/proc/qperf_metrics` 代码 | 已执行 `echo reset`，但未做单独 before/after 定量隔离 | +| compare | self compare | PASS | `target/qperf-validation/blk/compare-self/perf-compare/blk-self-smoke/compare.md` | 主要指标 delta 为 0，结论“基本无变化” | +| compare | cross compare | PASS | `target/qperf-validation/blk/compare-cross/perf-compare/blk-vs-net-cross/compare.md` | 不 crash，缺失字段显示 N/A；跨 workload 结论不应用作优化判断 | +| compatibility | old command | PASS | `target/qperf-validation/compat-old/perf/riscv64/latest/report.json` | 未传 marker/qperf-metrics 时仍可运行 | +| vsock | vhost-vsock 环境 | BLOCKED | `/dev/vhost-vsock` 检查 | 当前 host 无该设备，未做定量结论 | + +本轮发现并做了一个最小修复：`report.json` 的 artifacts 列表原先缺少 `profile.stdout`、`profile.stderr`、raw sample、summary、QEMU config 等已生成文件。已在 `tools/starry-syscall-harness/harness.py` 中补充，并通过 py_compile 与旧命令兼容性 smoke test。 + +## 4. blk 验证结果 + +命令： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --host-time \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:blk-read; dd if=/usr/bin/lto-dump of=/dev/null bs=64k; cat /proc/qperf_metrics; echo QPERF_END:blk-read' \ + --output-dir target/qperf-validation/blk +``` + +证据：`target/qperf-validation/blk/perf/riscv64/latest/report.json` + +| 指标 | 值 | +| --- | --- | +| dd bytes | `53601104` | +| dd elapsed | `5.794463` s | +| dd throughput | `9250400.597950146` B/s，约 `8.8 MB/s` | +| marker window duration | `5.951667225` s | +| boot samples excluded | `164` | +| post-window samples excluded | `492` | +| total workload samples | `590` | +| samples per MB | `11.007236` | +| instructions per MB | N/A | +| blocks per MB | N/A | +| host elapsed per MB | `0.235666` s/MB | +| host elapsed/user/sys | `12.631965` / `14.222615` / `0.750295` s | + +Top hotspot categories： + +| category | samples | percent | +| --- | ---: | ---: | +| `memcpy` | 173 | 29.3220% | +| `virtio_notify_kick` | 154 | 26.1017% | +| `virtqueue_add_notify_wait_pop` | 151 | 25.5932% | +| `block_io_path` | 108 | 18.3051% | +| `allocator` | 79 | 13.3898% | +| `scheduler_wait_preempt` | 10 | 1.6949% | + +Virtio/block counters： + +| counter | value | +| --- | ---: | +| `virtqueue_add_notify_wait_pop_count` | 13,780 | +| `virtqueue_add_count` | 13,847 | +| `virtio_notify_kick_count` | 13,847 | +| `virtqueue_pop_complete_count` | 13,783 | +| `virtqueue_depth_max` | 63 | +| `virtio_blk_read_requests` | 13,478 | +| `virtio_blk_read_bytes` | 55,195,136 | +| `virtio_blk_write_requests` | 302 | +| `virtio_blk_write_bytes` | 1,236,992 | + +判断：blk 已能支撑后续“同步 `add_notify_wait_pop` 是否下降、queue depth 是否被利用、blk read bytes/request 是否匹配 workload”的 A/B 验证。但当前 blk 报告缺少 `qperf/qperf.summary.txt`，导致 guest instructions/blocks per MB 为 N/A；这会削弱严肃的指令级归一化判断，需要修复 plugin summary 落盘或 QEMU 退出流程。 + +## 5. net 验证结果 + +用户给定命令在当前 Docker/WSL 环境下失败：host HTTP server 启动在 WSL host，guest 访问 Docker 内 QEMU slirp 的 `10.0.2.2:8000`，结果为 connection refused。失败证据：`target/qperf-validation/net/perf/riscv64/latest/profile.stdout`。 + +为验证工具本身，补跑了 container 内 HTTP server 版本，使 guest 的 `10.0.2.2:8000` 指向同一个 Docker 网络命名空间内的服务。证据：`target/qperf-validation/net-container/perf/riscv64/latest/report.json`。 + +| 指标 | 值 | +| --- | --- | +| wget bytes | `63543705` | +| wget elapsed | `7.299213151` s，来源为 marker window | +| wget throughput | `8705555.473646423` B/s | +| marker window duration | `7.299213151` s | +| boot samples excluded | `155` | +| post-window samples excluded | `0` | +| total workload samples | `722` | +| samples per MB | `11.362258` | +| instructions per MB | `18821395.746439` | +| blocks per MB | `2875126.497581` | +| host elapsed per MB | `0.141124` s/MB | +| host elapsed/user/sys | `8.967565` / `9.559295` / `0.818735` s | + +Top hotspot categories： + +| category | samples | percent | +| --- | ---: | ---: | +| `memcpy` | 220 | 30.4709% | +| `net_rx_tx_path` | 158 | 21.8837% | +| `allocator` | 114 | 15.7895% | +| `memmove` | 81 | 11.2188% | +| `scheduler_wait_preempt` | 21 | 2.9086% | +| `block_io_path` | 2 | 0.2770% | + +Virtio/net counters： + +| counter | value | +| --- | ---: | +| `virtio_net_rx_packets` | 44,141 | +| `virtio_net_rx_bytes` | 65,937,102 | +| `virtio_net_rx_copy_within_count` | 44,141 | +| `virtio_net_rx_copy_within_bytes` | 65,937,102 | +| `virtio_net_tx_packets` | 2,478 | +| `virtio_net_tx_bytes` | 149,322 | +| `virtio_net_tx_staging_copy_count` | 2,478 | +| `virtio_net_tx_staging_copy_bytes` | 149,322 | +| `virtio_net_inflight_insert_count` | 46,682 | +| `virtio_net_inflight_remove_count` | 46,618 | +| `virtio_net_inflight_get_count` | 46,618 | +| `virtqueue_depth_max` | 63 | + +判断：net 工具链已经能支撑 RX 去 `copy_within()`、TX staging copy 优化、inflight map 替换的 A/B 验证。需要注意，当前用户文档中的 host server 启动方式在 Docker/WSL 下不可复现，应改为 container 内 server、host 网络模式，或显式说明网络拓扑。 + +## 6. compare 验证结果 + +Self compare 命令： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/qperf-validation/blk/perf/riscv64/latest/report.json \ + --candidate target/qperf-validation/blk/perf/riscv64/latest/report.json \ + --name blk-self-smoke \ + --output-dir target/qperf-validation/blk/compare-self +``` + +输出： + +* `target/qperf-validation/blk/compare-self/perf-compare/blk-self-smoke/compare.json` +* `target/qperf-validation/blk/compare-self/perf-compare/blk-self-smoke/compare.md` +* `target/qperf-validation/blk/compare-self/perf-compare/blk-self-smoke/compare.csv` + +Self compare 结果为“基本无变化”，可比字段 delta 为 0。由于 blk 报告本身缺 guest instructions/blocks，相关字段显示 N/A。 + +Cross compare 命令： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-compare \ + --baseline target/qperf-validation/blk/perf/riscv64/latest/report.json \ + --candidate target/qperf-validation/net-container/perf/riscv64/latest/report.json \ + --name blk-vs-net-cross \ + --output-dir target/qperf-validation/blk/compare-cross +``` + +输出： + +* `target/qperf-validation/blk/compare-cross/perf-compare/blk-vs-net-cross/compare.json` +* `target/qperf-validation/blk/compare-cross/perf-compare/blk-vs-net-cross/compare.md` +* `target/qperf-validation/blk/compare-cross/perf-compare/blk-vs-net-cross/compare.csv` + +Cross compare 不 crash，Markdown 中缺失字段显示 N/A，说明 compare 对 schema 缺口有容错。但跨 workload 的自动结论显示“退化”，这不应解释为真实优化回归；compare 目前不校验 baseline/candidate 是否同一 workload、同一输入大小。 + +初次将 compare 输出写到 `target/qperf-validation/compare-self` 时失败，原因是该目录由 Docker/root 创建，host 用户无写权限。改写到 `target/qperf-validation/blk/compare-self` 后通过。后续应避免 Docker 创建 root-owned 顶层验证目录，或在 harness 中修正 uid/gid。 + +## 7. vsock 状态 + +当前 host 缺少 `/dev/vhost-vsock`： + +```text +ls: cannot access '/dev/vhost-vsock': No such file or directory +``` + +因此本轮未做 virtio-vsock 定量结论，也未伪造 vsock 指标。具备 vhost-vsock 的 Linux host 上应补测： + +```bash +python3 tools/starry-syscall-harness/harness.py perf-profile \ + --arch riscv64 \ + --host-time \ + --qperf-metrics \ + --start-marker QPERF_BEGIN \ + --stop-marker QPERF_END \ + --workload-timeout 45 \ + --shell-init-cmd 'echo reset > /proc/qperf_metrics; echo QPERF_BEGIN:vsock; ; cat /proc/qperf_metrics; echo QPERF_END:vsock' \ + --output-dir target/qperf-validation/vsock +``` + +补测时应在报告中记录 `/dev/vhost-vsock` 权限、QEMU vsock 参数、CID/port、workload bytes 与 elapsed。 + +## 8. 未达标项与风险 + +* runtime pause/resume 仍未验证为真实启停采样；当前能力主要依赖 timestamp 后处理过滤和 marker window 标注。结论应表述为“boot samples excluded by postprocess”，不能声称采样器运行时暂停。 +* blk 用例缺失 `qperf/qperf.summary.txt`，导致 guest instructions per MB 与 guest blocks per MB 为 N/A。这是归一化指标的关键缺口。 +* queue depth、notify/kick、pop/complete 计数是 driver-visible 近似统计，不是 virtqueue ring-level 精确硬件事件计数；当前使用 relaxed atomics，snapshot 不是强一致事务。 +* host perf 未启用，PMU 级 cycles/cache-miss 等 host 指标不存在。报告有明确 `未启用 host perf` 说明。 +* 用户给定 net 命令在当前 Docker/WSL 网络拓扑下失败。工具可用，但示例命令需要改成 container 内 HTTP server 或明确网络前提。 +* compare 对跨 workload 输入没有 guard，可能给出形式上的“退化/改善”结论；实际 A/B 应只比较同 workload、同输入、同 qperf 参数。 +* compare CSV 中缺失字段为空值，Markdown 显示 N/A；若后续自动消费 CSV，建议也输出显式 N/A。 +* `/proc/qperf_metrics reset` 已在 workload 中执行，但本轮未做独立 before/after 断言；建议补一个微型读写 reset 单测或 harness smoke。 +* 顶层 `target/qperf-validation` 可能被 Docker 创建为 root-owned，导致 host-side compare 输出 PermissionError。 + +## 9. 总体结论 + +结论：**PARTIAL**。 + +本轮改造达到 qperf 工具 MVP 的主要方向：marker window 可用，boot/post-window 样本能从 workload 报告中排除；工程分类热点、dd/wget/QPERF_METRIC parser、virtio-blk/net counters、A/B compare 都有可复现实验文件支撑。blk 和 net 的关键候选瓶颈已经能在 report 中直接看到。 + +但仍存在关键缺口：blk 运行缺 guest instruction/block summary，用户给定 net 命令在当前 Docker/WSL 拓扑下不可复现，采样窗口仍是后处理过滤而不是运行时 pause/resume，virtio counters 是 driver-visible 近似值。它可以支撑下一轮小规模 virtio 优化 A/B 验证，但报告必须保留这些限制，不能把当前数据解释为完整 PMU/virtqueue ring 级精确观测。 + +## 10. 下一步建议 + +1. net RX 去 `copy_within()` 的 A/B 优化验证：使用 `target/qperf-validation/net-container` 同样的 container 内 HTTP server 拓扑，比较 `virtio_net_rx_copy_within_bytes`、`memmove` category、throughput、samples per MB。 +2. net inflight `BTreeMap` 替换固定数组/slab 的 A/B 优化验证：比较 `virtio_net_inflight_insert/remove/get_count`、`net_inflight_btree` category、allocator category、host elapsed per MB。 +3. blk `read_blocks_nb()` / `complete_read_blocks()` 最小 pending-read 原型验证：比较 `virtqueue_add_notify_wait_pop_count`、`virtio_notify_kick_count`、`virtqueue_depth_max`、blk throughput、samples per MB。 +4. 修复 blk `qperf.summary.txt` 缺失问题后重跑 blk；要求 `guest_instructions_per_MB` 和 `guest_blocks_per_MB` 不再是 N/A。 +5. 在具备 `/dev/vhost-vsock` 的 Linux host 上补测 vsock，并把环境阻塞、CID/port、bytes、elapsed、vsock counters 明确写入 report。 diff --git a/scripts/axbuild/src/context/workspace.rs b/scripts/axbuild/src/context/workspace.rs index d1f1dba780..7b34711458 100644 --- a/scripts/axbuild/src/context/workspace.rs +++ b/scripts/axbuild/src/context/workspace.rs @@ -1,5 +1,6 @@ use std::{ collections::HashSet, + env, path::{Path, PathBuf}, }; @@ -38,7 +39,17 @@ pub(crate) fn workspace_manifest_path() -> anyhow::Result { } pub(crate) fn axbuild_tmp_dir(workspace_root: &Path) -> PathBuf { - workspace_root.join("tmp").join("axbuild") + env::var_os("AXBUILD_TMP_DIR") + .filter(|value| !value.is_empty()) + .map(PathBuf::from) + .map(|path| { + if path.is_absolute() { + path + } else { + workspace_root.join(path) + } + }) + .unwrap_or_else(|| workspace_root.join("tmp").join("axbuild")) } pub(crate) fn workspace_manifest_path_in(workspace_root: &Path) -> PathBuf { diff --git a/scripts/axbuild/src/lib.rs b/scripts/axbuild/src/lib.rs index 5fb5c13952..17ed298e03 100644 --- a/scripts/axbuild/src/lib.rs +++ b/scripts/axbuild/src/lib.rs @@ -81,7 +81,7 @@ enum Commands { /// StarryOS build commands Starry { #[command(subcommand)] - command: starry::Command, + command: Box, }, } @@ -100,6 +100,6 @@ async fn run_root_cli(cli: Cli) -> anyhow::Result<()> { Commands::Backtrace { command } => backtrace::execute(command), Commands::Axvisor { command } => Axvisor::new()?.execute(command).await, Commands::Arceos { command } => ArceOS::new()?.execute(command).await, - Commands::Starry { command } => Starry::new()?.execute(command).await, + Commands::Starry { command } => Starry::new()?.execute(*command).await, } } diff --git a/scripts/axbuild/src/starry/mod.rs b/scripts/axbuild/src/starry/mod.rs index f2f72450e5..62c9f00858 100644 --- a/scripts/axbuild/src/starry/mod.rs +++ b/scripts/axbuild/src/starry/mod.rs @@ -1,4 +1,7 @@ -use std::path::{Path, PathBuf}; +use std::{ + fmt, + path::{Path, PathBuf}, +}; use clap::{Args, Subcommand, ValueEnum}; use ostool::{ @@ -25,6 +28,7 @@ pub enum Command { /// Build StarryOS application Build(ArgsBuild), /// Build and run StarryOS application + #[command(alias = "run")] Qemu(ArgsQemu), /// Generate a default StarryOS board config Defconfig(ArgsDefconfig), @@ -74,24 +78,188 @@ pub struct ArgsQemu { /// Override the rootfs disk image path (skips auto-download). #[arg(long, value_name = "IMAGE")] pub rootfs: Option, + + #[command(flatten)] + pub perf: ArgsQemuPerf, +} + +#[derive(Args, Debug, Clone, Default)] +pub struct ArgsQemuPerf { + /// Profile this run with qperf instead of launching a plain QEMU session. + #[arg(long)] + pub perf: bool, + #[arg(long = "perf-case", value_name = "NAME")] + pub case: Option, + #[arg(long = "perf-workload", value_name = "CMD")] + pub workload: Option, + #[arg(long = "perf-shell-prefix", value_name = "PREFIX")] + pub shell_prefix: Option, + #[arg(long = "perf-output-dir", value_name = "DIR")] + pub output_dir: Option, + #[arg(long = "perf-start-marker", value_name = "MARKER")] + pub start_marker: Option, + #[arg(long = "perf-stop-marker", value_name = "MARKER")] + pub stop_marker: Option, + #[arg(long = "perf-timeout", value_name = "SECONDS")] + pub timeout: Option, + #[arg(long = "perf-workload-timeout", value_name = "SECONDS")] + pub workload_timeout: Option, + #[arg(long = "perf-freq", value_name = "HZ")] + pub freq: Option, + #[arg(long = "perf-max-depth", value_name = "DEPTH")] + pub max_depth: Option, + #[arg(long = "perf-mode", value_enum)] + pub mode: Option, + #[arg(long = "perf-format", value_enum)] + pub format: Option, + #[arg(long = "perf-top", value_name = "N")] + pub top: Option, + #[arg(long = "perf-min-percent", value_name = "PERCENT")] + pub min_percent: Option, + #[arg(long = "perf-host-time")] + pub host_time: bool, + #[arg(long = "perf-no-host-time")] + pub no_host_time: bool, + #[arg(long = "perf-host-perf")] + pub host_perf: bool, + #[arg(long = "perf-host-perf-events", value_name = "EVENTS")] + pub host_perf_events: Option, + /// Parse QPERF_METRIC lines from guest stdout into the generated report. + /// + /// Kernel-side counter instrumentation must be enabled by the profiled + /// workload or by a separate StarryOS feature. + #[arg(long = "perf-qperf-metrics")] + pub qperf_metrics: bool, + #[arg(long = "perf-qemu-arg", value_name = "ARG", allow_hyphen_values = true)] + pub qemu_args: Vec, + #[arg(long = "perf-flamegraph")] + pub flamegraph: bool, + #[arg(long = "perf-flamegraph-kind", value_enum)] + pub flamegraph_kind: Option, + #[arg(long = "perf-full-stack")] + pub full_stack: bool, + #[arg(long = "perf-callchain", value_enum)] + pub callchain: Option, + #[arg(long = "perf-debuginfo")] + pub debuginfo: bool, + #[arg(long = "perf-force-frame-pointers")] + pub force_frame_pointers: bool, + #[arg(long = "perf-demangle")] + pub demangle: bool, + #[arg(long = "perf-no-truncate")] + pub no_truncate: bool, + #[arg(long = "perf-symbol-style", value_enum)] + pub symbol_style: Option, + #[arg(long = "perf-focus", value_name = "REGEX")] + pub focus: Option, } #[derive(Args, Debug, Clone)] pub struct ArgsPerf { + /// Profile case name used in the default output path. + #[arg(long, default_value = "boot")] + pub case: String, #[arg(long)] pub arch: Option, #[arg(long, default_value_t = 99)] pub freq: u32, - #[arg(long)] + #[arg(long = "out", hide = true)] pub out: Option, + /// Output root. Final reports go under /perf//latest. + #[arg(long)] + pub output_dir: Option, #[arg(long, value_enum, default_value_t = PerfFormat::All)] pub format: PerfFormat, - #[arg(long, default_value_t = 64)] + #[arg(long, default_value_t = 128)] pub max_depth: usize, #[arg(long, value_name = "SECONDS", default_value_t = 20)] pub timeout: u64, - #[arg(long, value_name = "CPUS")] - pub smp: Option, + #[arg(long, value_enum, default_value_t = PerfMode::Tb)] + pub mode: PerfMode, + #[arg(long, default_value_t = 80)] + pub top: usize, + #[arg(long, default_value_t = 0.3)] + pub min_percent: f64, + #[arg(long)] + pub debug: bool, + #[arg(long)] + pub kernel_filter: bool, + /// Collect host wall/user/system CPU time metrics for the QEMU process wrapper. + #[arg(long)] + pub host_time: bool, + /// Disable the cargo starry perf default host-time metrics. + #[arg(long)] + pub no_host_time: bool, + /// Run QEMU under host perf stat. These are host/QEMU process metrics, not guest PMU values. + #[arg(long)] + pub host_perf: bool, + /// Comma-separated host perf stat events used with --host-perf. + #[arg( + long, + default_value = "task-clock,cycles,instructions,cache-references,cache-misses,\ + context-switches,cpu-migrations,page-faults" + )] + pub host_perf_events: String, + /// Send this command to the guest shell after the qperf boot prompt appears. + #[arg(long, visible_alias = "workload")] + pub shell_init_cmd: Option, + /// Prompt substring used before sending --shell-init-cmd. + #[arg(long)] + pub shell_prefix: Option, + /// Append one raw QEMU argument. Repeat for options and values. + #[arg(long = "qemu-arg", value_name = "ARG", allow_hyphen_values = true)] + pub qemu_args: Vec, + /// Guest stdout marker that starts the workload sampling window. + #[arg(long)] + pub start_marker: Option, + /// Guest stdout marker that stops the workload sampling window. + #[arg(long)] + pub stop_marker: Option, + /// Stop QEMU if the workload window stays open longer than this many seconds. + #[arg(long, value_name = "SECONDS")] + pub workload_timeout: Option, + /// Parse QPERF_METRIC lines from guest stdout into the generated report. + /// + /// Kernel-side counter instrumentation must be enabled by the profiled + /// workload or by a separate StarryOS feature. + #[arg(long)] + pub qperf_metrics: bool, + /// Request SVG flamegraph generation even when --format is folded. + #[arg(long)] + pub flamegraph: bool, + /// Flamegraph view format. + #[arg(long, value_enum, default_value_t = PerfFlamegraphKind::Svg)] + pub flamegraph_kind: PerfFlamegraphKind, + /// Preserve the deepest stack qperf can collect for this build. + #[arg(long)] + pub full_stack: bool, + /// qperf callchain collection mode. `leaf` is fastest; `fp` requires frame pointers. + #[arg(long = "perf-callchain", visible_alias = "callchain", value_enum)] + pub callchain: Option, + /// Add DWARF debug info and keep symbols for qperf symbolization. + #[arg(long = "perf-debuginfo")] + pub debuginfo: bool, + /// Force frame pointers for qperf FP unwinding. + #[arg(long = "perf-force-frame-pointers")] + pub force_frame_pointers: bool, + /// Force Rust demangling in qperf-analyzer. + #[arg(long)] + pub demangle: bool, + /// Keep tiny frames in SVG output by setting flamegraph min width to zero. + #[arg(long)] + pub no_truncate: bool, + /// Include kernel symbols in symbolized stacks. This is the default for StarryOS kernels. + #[arg(long)] + pub include_kernel_symbols: bool, + /// Include user symbols when available. Current StarryOS qperf only resolves the kernel ELF. + #[arg(long)] + pub include_user_symbols: bool, + /// Folded-stack symbol style. + #[arg(long, value_enum, default_value_t = PerfSymbolStyle::Full)] + pub symbol_style: PerfSymbolStyle, + /// Generate an additional focused folded stack/flamegraph for matching frames. + #[arg(long, value_name = "REGEX")] + pub focus: Option, } #[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] @@ -102,6 +270,72 @@ pub enum PerfFormat { All, } +#[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] +pub enum PerfMode { + Tb, + Insn, +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] +pub enum PerfCallchain { + Leaf, + Fp, + Logical, +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] +pub enum PerfFlamegraphKind { + Svg, + Html, + Folded, +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] +pub enum PerfSymbolStyle { + Full, + Short, + Module, +} + +impl fmt::Display for PerfMode { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::Tb => "tb", + Self::Insn => "insn", + }) + } +} + +impl fmt::Display for PerfCallchain { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::Leaf => "leaf", + Self::Fp => "fp", + Self::Logical => "logical", + }) + } +} + +impl fmt::Display for PerfFlamegraphKind { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::Svg => "svg", + Self::Html => "html", + Self::Folded => "folded", + }) + } +} + +impl fmt::Display for PerfSymbolStyle { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::Full => "full", + Self::Short => "short", + Self::Module => "module", + }) + } +} + #[derive(Args)] pub struct ArgsUboot { #[command(flatten)] @@ -162,6 +396,100 @@ impl From<&ArgsBuild> for StarryCliArgs { } } +impl ArgsQemuPerf { + fn has_overrides(&self) -> bool { + self.case.is_some() + || self.workload.is_some() + || self.shell_prefix.is_some() + || self.output_dir.is_some() + || self.start_marker.is_some() + || self.stop_marker.is_some() + || self.timeout.is_some() + || self.workload_timeout.is_some() + || self.freq.is_some() + || self.max_depth.is_some() + || self.mode.is_some() + || self.format.is_some() + || self.top.is_some() + || self.min_percent.is_some() + || self.host_time + || self.no_host_time + || self.host_perf + || self.host_perf_events.is_some() + || self.qperf_metrics + || !self.qemu_args.is_empty() + || self.flamegraph + || self.flamegraph_kind.is_some() + || self.full_stack + || self.callchain.is_some() + || self.debuginfo + || self.force_frame_pointers + || self.demangle + || self.no_truncate + || self.symbol_style.is_some() + || self.focus.is_some() + } +} + +fn perf_args_from_qemu(args: ArgsQemu) -> anyhow::Result { + if args.qemu_config.is_some() || args.rootfs.is_some() { + anyhow::bail!( + "cargo starry run --perf currently uses the default StarryOS qperf QEMU/rootfs flow; \ + --qemu-config and --rootfs are not supported with --perf yet" + ); + } + if args.build.config.is_some() || args.build.target.is_some() || args.build.smp.is_some() { + anyhow::bail!( + "cargo starry run --perf currently supports --arch and --debug build overrides; use \ + cargo starry perf for the default qperf path or plain cargo starry qemu for custom \ + --config/--target/--smp runs" + ); + } + let perf = args.perf; + Ok(ArgsPerf { + case: perf.case.unwrap_or_else(|| "boot".to_string()), + arch: args.build.arch, + freq: perf.freq.unwrap_or(99), + out: None, + output_dir: perf.output_dir, + format: perf.format.unwrap_or(PerfFormat::All), + max_depth: perf.max_depth.unwrap_or(128), + timeout: perf.timeout.unwrap_or(20), + mode: perf.mode.unwrap_or(PerfMode::Tb), + top: perf.top.unwrap_or(80), + min_percent: perf.min_percent.unwrap_or(0.3), + debug: args.build.debug, + kernel_filter: false, + host_time: perf.host_time, + no_host_time: perf.no_host_time, + host_perf: perf.host_perf, + host_perf_events: perf.host_perf_events.unwrap_or_else(|| { + "task-clock,cycles,instructions,cache-references,cache-misses,context-switches,\ + cpu-migrations,page-faults" + .to_string() + }), + shell_init_cmd: perf.workload, + shell_prefix: perf.shell_prefix, + qemu_args: perf.qemu_args, + start_marker: perf.start_marker, + stop_marker: perf.stop_marker, + workload_timeout: perf.workload_timeout, + qperf_metrics: perf.qperf_metrics, + flamegraph: perf.flamegraph, + flamegraph_kind: perf.flamegraph_kind.unwrap_or(PerfFlamegraphKind::Svg), + full_stack: perf.full_stack, + callchain: perf.callchain, + debuginfo: perf.debuginfo, + force_frame_pointers: perf.force_frame_pointers, + demangle: perf.demangle, + no_truncate: perf.no_truncate, + include_kernel_symbols: true, + include_user_symbols: false, + symbol_style: perf.symbol_style.unwrap_or(PerfSymbolStyle::Full), + focus: perf.focus, + }) +} + impl Starry { pub fn new() -> anyhow::Result { let app = AppContext::new()?; @@ -191,6 +519,12 @@ impl Starry { } async fn qemu(&mut self, args: ArgsQemu) -> anyhow::Result<()> { + if args.perf.perf { + return self.perf(perf_args_from_qemu(args)?).await; + } + if args.perf.has_overrides() { + anyhow::bail!("--perf-* options require --perf"); + } let request = self.prepare_request( (&args.build).into(), args.qemu_config, @@ -688,6 +1022,143 @@ mod tests { } } + #[test] + fn command_parses_perf_workload_options() { + #[derive(Parser)] + struct Cli { + #[command(subcommand)] + command: Command, + } + + let cli = Cli::try_parse_from([ + "starry", + "perf", + "--arch", + "riscv64", + "--shell-init-cmd", + "echo qperf", + "--shell-prefix", + "root@starry:", + "--host-time", + "--host-perf", + "--host-perf-events", + "task-clock,instructions", + "--qemu-arg=-device", + "--qemu-arg=vhost-vsock-pci,guest-cid=3", + "--start-marker", + "QPERF_BEGIN", + "--stop-marker", + "QPERF_END", + "--workload-timeout", + "5", + "--qperf-metrics", + ]) + .unwrap(); + + match cli.command { + Command::Perf(args) => { + assert_eq!(args.arch.as_deref(), Some("riscv64")); + assert_eq!(args.shell_init_cmd.as_deref(), Some("echo qperf")); + assert_eq!(args.shell_prefix.as_deref(), Some("root@starry:")); + assert!(args.host_time); + assert!(args.host_perf); + assert_eq!(args.host_perf_events, "task-clock,instructions"); + assert_eq!( + args.qemu_args, + vec!["-device", "vhost-vsock-pci,guest-cid=3"] + ); + assert_eq!(args.start_marker.as_deref(), Some("QPERF_BEGIN")); + assert_eq!(args.stop_marker.as_deref(), Some("QPERF_END")); + assert_eq!(args.workload_timeout, Some(5)); + assert!(args.qperf_metrics); + } + _ => panic!("expected perf command"), + } + } + + #[test] + fn command_parses_perf_flamegraph_options() { + #[derive(Parser)] + struct Cli { + #[command(subcommand)] + command: Command, + } + + let cli = Cli::try_parse_from([ + "starry", + "perf", + "--case", + "blk-read", + "--workload", + "echo qperf", + "--flamegraph-kind", + "html", + "--full-stack", + "--no-truncate", + "--symbol-style", + "module", + "--focus", + "virtio|VirtQueue", + "--min-percent", + "0", + ]) + .unwrap(); + + match cli.command { + Command::Perf(args) => { + assert_eq!(args.case, "blk-read"); + assert_eq!(args.shell_init_cmd.as_deref(), Some("echo qperf")); + assert_eq!(args.flamegraph_kind, PerfFlamegraphKind::Html); + assert!(args.full_stack); + assert!(args.no_truncate); + assert_eq!(args.symbol_style, PerfSymbolStyle::Module); + assert_eq!(args.focus.as_deref(), Some("virtio|VirtQueue")); + assert_eq!(args.min_percent, 0.0); + } + _ => panic!("expected perf command"), + } + } + + #[test] + fn command_parses_run_perf_alias() { + #[derive(Parser)] + struct Cli { + #[command(subcommand)] + command: Command, + } + + let cli = Cli::try_parse_from([ + "starry", + "run", + "--arch", + "riscv64", + "--perf", + "--perf-case", + "net-wget", + "--perf-workload", + "echo qperf", + "--perf-qperf-metrics", + "--perf-symbol-style", + "short", + "--perf-focus", + "memcpy|memmove", + ]) + .unwrap(); + + match cli.command { + Command::Qemu(args) => { + assert_eq!(args.build.arch.as_deref(), Some("riscv64")); + assert!(args.perf.perf); + assert_eq!(args.perf.case.as_deref(), Some("net-wget")); + assert_eq!(args.perf.workload.as_deref(), Some("echo qperf")); + assert!(args.perf.qperf_metrics); + assert_eq!(args.perf.symbol_style, Some(PerfSymbolStyle::Short)); + assert_eq!(args.perf.focus.as_deref(), Some("memcpy|memmove")); + } + _ => panic!("expected qemu command"), + } + } + #[test] fn command_parses_test_board() { #[derive(Parser)] diff --git a/scripts/axbuild/src/starry/perf.rs b/scripts/axbuild/src/starry/perf.rs index 9800b5ca70..f24d60c3e0 100644 --- a/scripts/axbuild/src/starry/perf.rs +++ b/scripts/axbuild/src/starry/perf.rs @@ -1,21 +1,31 @@ use std::{ - env, fs, + env, + ffi::OsString, + fs, fs::File, - io::{BufRead, BufReader, Write}, + io::{BufRead, BufReader, Read, Write}, path::{Path, PathBuf}, process::{Command, ExitStatus, Stdio}, + sync::mpsc, + thread, + time::{Duration, Instant}, }; use anyhow::{Context, bail}; +use object::{Object, ObjectSection}; +use ostool::build::config::Cargo; use serde::{Deserialize, Serialize}; -use super::{ArgsBuild, ArgsPerf, PerfFormat, Starry, build, rootfs}; +use super::{ + ArgsBuild, ArgsPerf, PerfCallchain, PerfFlamegraphKind, PerfFormat, Starry, build, rootfs, +}; use crate::{ context::{SnapshotPersistence, StarryCliArgs, starry_target_for_arch_checked}, support::process::ProcessExt, }; const QPERF_QUEUE_SIZE: usize = 4096; +const DEFAULT_STARRY_SHELL_PREFIX: &str = "root@starry:"; #[derive(Deserialize, Serialize)] struct PerfQemuConfig { @@ -27,6 +37,9 @@ struct PerfQemuConfig { shell_prefix: Option, shell_init_cmd: Option, timeout: Option, + start_marker: Option, + stop_marker: Option, + workload_timeout: Option, } struct QperfTools { @@ -35,12 +48,105 @@ struct QperfTools { } struct PerfOutputs { + work_dir: PathBuf, dir: PathBuf, raw: PathBuf, folded: PathBuf, flamegraph: PathBuf, + folded_boot: PathBuf, + flamegraph_boot: PathBuf, + folded_workload: PathBuf, + flamegraph_workload: PathBuf, + folded_post: PathBuf, + flamegraph_post: PathBuf, + folded_focus: PathBuf, + flamegraph_focus: PathBuf, + stack_depth_summary: PathBuf, + flamegraph_html: PathBuf, summary: PathBuf, qemu_config: PathBuf, + host_time: PathBuf, + host_perf: PathBuf, + resolve_stats: PathBuf, + window: PathBuf, + qmp_socket: PathBuf, + profile_stdout: PathBuf, + profile_stderr: PathBuf, + report_json: PathBuf, + report_md: PathBuf, + hotspots_csv: PathBuf, + hotspot_categories_csv: PathBuf, +} + +#[derive(Default, Serialize)] +struct PerfWindowReport { + enabled: bool, + start_marker: Option, + stop_marker: Option, + start_time: Option, + stop_time: Option, + duration_sec: Option, + workload_timeout: Option, + truncated_by_timeout: bool, + boot_samples_excluded: Option, + stop_requested: bool, + stop_method: Option, + warnings: Vec, + method: String, +} + +struct QemuRun { + status: ExitStatus, + window: PerfWindowReport, +} + +#[derive(Clone, Copy, Default)] +struct ChildResourceUsage { + user_micros: i128, + system_micros: i128, + major_faults: i128, + minor_faults: i128, + voluntary_context_switches: i128, + involuntary_context_switches: i128, +} + +impl ChildResourceUsage { + fn delta_since(self, before: Self) -> Self { + Self { + user_micros: nonnegative_delta(self.user_micros, before.user_micros), + system_micros: nonnegative_delta(self.system_micros, before.system_micros), + major_faults: nonnegative_delta(self.major_faults, before.major_faults), + minor_faults: nonnegative_delta(self.minor_faults, before.minor_faults), + voluntary_context_switches: nonnegative_delta( + self.voluntary_context_switches, + before.voluntary_context_switches, + ), + involuntary_context_switches: nonnegative_delta( + self.involuntary_context_switches, + before.involuntary_context_switches, + ), + } + } + + fn user_seconds(self) -> f64 { + self.user_micros as f64 / 1_000_000.0 + } + + fn system_seconds(self) -> f64 { + self.system_micros as f64 / 1_000_000.0 + } +} + +#[derive(Clone, Copy)] +struct AddressRange { + start: u64, + end: u64, +} + +#[derive(Clone, Copy)] +struct KernelTextRange { + virt: AddressRange, + phys: Option, } pub(super) async fn run(starry: &mut Starry, args: ArgsPerf) -> anyhow::Result<()> { @@ -50,16 +156,29 @@ pub(super) async fn run(starry: &mut Starry, args: ArgsPerf) -> anyhow::Result<( .clone() .unwrap_or_else(|| crate::context::DEFAULT_STARRY_ARCH.to_string()); let target = starry_target_for_arch_checked(&arch)?.to_string(); - let outputs = prepare_outputs(starry.app.workspace_root(), &arch, args.out.as_deref())?; + let outputs = prepare_outputs( + starry.app.workspace_root(), + &arch, + &args.case, + args.out.as_deref(), + args.output_dir.as_deref(), + )?; + let _axbuild_tmp_dir = set_env_if_missing( + "AXBUILD_TMP_DIR", + outputs.work_dir.join("axbuild-tmp").into_os_string(), + )?; + let generate_svg = args.flamegraph + || matches!(args.format, PerfFormat::Svg | PerfFormat::All) + && !matches!(args.flamegraph_kind, PerfFlamegraphKind::Folded); - let tools = build_qperf_tools(starry.app.workspace_root())?; + let tools = build_qperf_tools(starry.app.workspace_root(), generate_svg)?; let build_args = ArgsBuild { config: None, arch: Some(arch.clone()), target: None, - smp: args.smp, - debug: true, + smp: None, + debug: args.debug, }; let request = starry.prepare_request( StarryCliArgs::from(&build_args), @@ -68,48 +187,127 @@ pub(super) async fn run(starry: &mut Starry, args: ArgsPerf) -> anyhow::Result<( SnapshotPersistence::Store, )?; - let cargo = build::load_cargo_config(&request)?; - starry.app.set_debug_mode(true)?; + let mut cargo = build::load_cargo_config(&request)?; + apply_perf_cargo_features(&mut cargo, &args); + starry.app.set_debug_mode(args.debug)?; starry .app .build(cargo, request.build_info_path.clone()) .await?; rootfs::ensure_qemu_rootfs_ready(&request, starry.app.workspace_root(), None).await?; - let cargo = build::load_cargo_config(&request)?; + let mut cargo = build::load_cargo_config(&request)?; + apply_perf_cargo_features(&mut cargo, &args); let qemu = rootfs::load_patched_qemu_config(starry, &request, &cargo, None, true).await?; - write_qemu_config(&outputs, &tools, &args, qemu.args)?; + let elf = kernel_elf_path(starry.app.workspace_root(), &target, args.debug); + let axconfig_path = cargo.env.get("AX_CONFIG_PATH").map(PathBuf::from); + let text_range = detect_kernel_text_range(&elf, axconfig_path.as_deref())?; + write_qemu_config(&outputs, &tools, &args, &arch, qemu.args, text_range)?; - let kernel_bin = kernel_bin_path(starry.app.workspace_root(), &target); - let qemu_status = run_qemu_direct(&outputs, &args, &arch, &kernel_bin)?; - if !qemu_status.success() { + let kernel_bin = kernel_bin_path(starry.app.workspace_root(), &target, args.debug); + let qemu_run = run_qemu_direct(&outputs, &args, &arch, &kernel_bin)?; + if !qemu_run.status.success() { if !file_nonempty(&outputs.raw) { - bail!("qperf QEMU run failed before producing samples: {qemu_status}"); + bail!( + "qperf QEMU run failed before producing samples: {}", + qemu_run.status + ); } - eprintln!("qperf: QEMU ended with {qemu_status} after producing samples"); + eprintln!( + "qperf: QEMU ended with {} after producing samples", + qemu_run.status + ); } - let elf = kernel_elf_path(starry.app.workspace_root(), &target); - run_analyzer(&tools.analyzer, &elf, &outputs.raw, &outputs.folded)?; + run_analyzer(AnalyzerRun { + analyzer: &tools.analyzer, + elf: &elf, + raw: &outputs.raw, + folded: &outputs.folded, + flamegraph: &outputs.flamegraph, + resolve_stats: &outputs.resolve_stats, + depth_summary: Some(&outputs.stack_depth_summary), + generate_svg, + top_n: args.top, + start_sec: qemu_run.window.start_time, + stop_sec: qemu_run.window.stop_time, + symbol_style: args.symbol_style.to_string(), + demangle: true, + focus: None, + min_percent: flamegraph_min_percent(&args), + })?; - let flamegraph_generated = if matches!(args.format, PerfFormat::Svg | PerfFormat::All) { + generate_phase_flamegraphs( + &tools, + &elf, + &outputs, + &args, + &qemu_run.window, + generate_svg, + )?; + generate_focus_flamegraph(&tools, &elf, &outputs, &args, generate_svg)?; + + let flamegraph_generated = if generate_svg && !file_nonempty(&outputs.flamegraph) { try_generate_flamegraph(&outputs.folded, &outputs.flamegraph)? } else { - false + generate_svg && file_nonempty(&outputs.flamegraph) }; - write_summary( - &outputs, - &tools, - &elf, - &arch, - &target, - &args, + write_summary(SummaryInputs { + outputs: &outputs, + tools: &tools, + elf: &elf, + arch: &arch, + target: &target, + args: &args, flamegraph_generated, - )?; - print_report(&outputs, flamegraph_generated); + window: &qemu_run.window, + })?; + write_flamegraph_html(&outputs, args.flamegraph_kind, flamegraph_generated)?; + run_report_postprocess(&outputs, &args, &arch, exit_status_code(&qemu_run.status))?; + print_report(&outputs, &args); Ok(()) } +fn apply_perf_cargo_features(cargo: &mut Cargo, args: &ArgsPerf) { + cargo.features.extend([ + "ax-driver/virtio-blk".to_string(), + "ax-driver/virtio-net".to_string(), + "ax-driver/virtio-socket".to_string(), + ]); + cargo.features.sort(); + cargo.features.dedup(); + if perf_needs_debuginfo(args) { + cargo.env.insert("DWARF".to_string(), "y".to_string()); + } + if perf_needs_frame_pointers(args) { + cargo.env.insert("BACKTRACE".to_string(), "y".to_string()); + } + apply_perf_rustflags(cargo, args); +} + +fn apply_perf_rustflags(cargo: &mut Cargo, args: &ArgsPerf) { + let mut flags = Vec::new(); + if perf_needs_debuginfo(args) { + flags.push("-Cdebuginfo=2".to_string()); + flags.push("-Cstrip=none".to_string()); + } + if perf_needs_frame_pointers(args) { + flags.push("-Cforce-frame-pointers=yes".to_string()); + } + if flags.is_empty() { + return; + } + + cargo + .env + .insert("CARGO_ENCODED_RUSTFLAGS".to_string(), flags.join("\x1f")); + cargo.args.push("--config".to_string()); + let rustflags = toml::Value::Array(flags.into_iter().map(toml::Value::String).collect()); + cargo + .args + .push(format!("target.'{}'.rustflags={rustflags}", cargo.target)); +} + fn validate_args(args: &ArgsPerf) -> anyhow::Result<()> { if args.freq == 0 { bail!("--freq must be greater than 0"); @@ -117,33 +315,227 @@ fn validate_args(args: &ArgsPerf) -> anyhow::Result<()> { if args.max_depth == 0 { bail!("--max-depth must be greater than 0"); } + if args.min_percent < 0.0 { + bail!("--min-percent must be non-negative"); + } if matches!(args.format, PerfFormat::Pprof) { bail!("--format pprof is not supported yet; use --format folded, svg, or all"); } + if args + .shell_init_cmd + .as_deref() + .is_some_and(|cmd| cmd.trim().is_empty()) + { + bail!("--shell-init-cmd must not be empty"); + } + if args + .shell_prefix + .as_deref() + .is_some_and(|prefix| prefix.is_empty()) + { + bail!("--shell-prefix must not be empty"); + } + if args.host_perf && args.host_perf_events.trim().is_empty() { + bail!("--host-perf-events must not be empty when --host-perf is set"); + } + if matches!(effective_callchain(args), PerfCallchain::Logical) { + bail!( + "--perf-callchain logical is not implemented yet; use --perf-callchain fp or \ + --full-stack for frame-pointer unwinding" + ); + } + if args.qperf_metrics { + eprintln!( + "qperf: --qperf-metrics parses QPERF_METRIC lines from guest stdout; this tools-only \ + path does not enable kernel-side instrumentation automatically" + ); + } + if args.include_user_symbols { + eprintln!( + "qperf: --include-user-symbols requested, but current analyzer resolves only the \ + StarryOS kernel ELF; user symbols will remain unresolved unless they are present in \ + the kernel image" + ); + } + if args + .start_marker + .as_deref() + .is_some_and(|marker| marker.trim().is_empty()) + { + bail!("--start-marker must not be empty"); + } + if args + .stop_marker + .as_deref() + .is_some_and(|marker| marker.trim().is_empty()) + { + bail!("--stop-marker must not be empty"); + } + if args.workload_timeout == Some(0) { + bail!("--workload-timeout must be greater than 0"); + } Ok(()) } -fn prepare_outputs(root: &Path, arch: &str, out: Option<&Path>) -> anyhow::Result { - let dir = out.map(PathBuf::from).unwrap_or_else(|| { - root.join("target") - .join("qperf") - .join(arch) - .join(chrono::Utc::now().format("%Y%m%d-%H%M%S").to_string()) - }); +fn host_time_enabled(args: &ArgsPerf) -> bool { + args.host_time || !args.no_host_time +} + +fn flamegraph_min_percent(args: &ArgsPerf) -> f64 { + if args.no_truncate { + 0.0 + } else { + args.min_percent + } +} + +fn effective_max_depth(args: &ArgsPerf) -> usize { + if args.full_stack { + args.max_depth.max(256) + } else { + args.max_depth + } +} + +fn effective_callchain(args: &ArgsPerf) -> PerfCallchain { + if args.full_stack { + PerfCallchain::Fp + } else { + args.callchain.unwrap_or(PerfCallchain::Leaf) + } +} + +fn perf_needs_debuginfo(args: &ArgsPerf) -> bool { + args.full_stack || args.debuginfo +} + +fn perf_needs_frame_pointers(args: &ArgsPerf) -> bool { + args.full_stack + || args.force_frame_pointers + || matches!(effective_callchain(args), PerfCallchain::Fp) +} + +struct ScopedEnvVar { + key: &'static str, + previous: Option, + active: bool, +} + +impl Drop for ScopedEnvVar { + fn drop(&mut self) { + if !self.active { + return; + } + match &self.previous { + Some(value) => { + // SAFETY: qperf runs this CLI flow serially and restores the process + // environment before returning to the caller. + unsafe { env::set_var(self.key, value) }; + } + None => { + // SAFETY: qperf runs this CLI flow serially and restores the process + // environment before returning to the caller. + unsafe { env::remove_var(self.key) }; + } + } + } +} + +fn set_env_if_missing(key: &'static str, value: OsString) -> anyhow::Result { + let previous = env::var_os(key); + if previous.as_ref().is_some_and(|value| !value.is_empty()) { + return Ok(ScopedEnvVar { + key, + previous, + active: false, + }); + } + let path = PathBuf::from(&value); + fs::create_dir_all(&path) + .with_context(|| format!("failed to create {key} directory {}", path.display()))?; + // SAFETY: qperf runs this CLI flow serially before spawning worker threads that depend on + // axbuild paths. + unsafe { env::set_var(key, &value) }; + Ok(ScopedEnvVar { + key, + previous, + active: true, + }) +} + +fn prepare_outputs( + root: &Path, + arch: &str, + case: &str, + out: Option<&Path>, + output_dir: Option<&Path>, +) -> anyhow::Result { + let (work_dir, dir) = if let Some(out) = out { + let dir = PathBuf::from(out); + let work_dir = dir + .parent() + .map(Path::to_path_buf) + .unwrap_or_else(|| dir.clone()); + (work_dir, dir) + } else { + let output_root = output_dir + .map(PathBuf::from) + .unwrap_or_else(|| root.join("target").join("qperf").join(case)); + let work_dir = output_root.join("perf").join(arch).join("latest"); + let dir = work_dir.join("qperf"); + (work_dir, dir) + }; + if out.is_none() && work_dir.exists() { + fs::remove_dir_all(&work_dir).with_context(|| { + format!( + "failed to remove previous qperf output directory {}", + work_dir.display() + ) + })?; + } fs::create_dir_all(&dir) .with_context(|| format!("failed to create qperf output directory {}", dir.display()))?; + fs::create_dir_all(&work_dir).with_context(|| { + format!( + "failed to create qperf work directory {}", + work_dir.display() + ) + })?; Ok(PerfOutputs { + work_dir: work_dir.clone(), raw: dir.join("qperf.bin"), folded: dir.join("stack.folded"), flamegraph: dir.join("flamegraph.svg"), + folded_boot: dir.join("stack.boot.folded"), + flamegraph_boot: dir.join("flamegraph.boot.svg"), + folded_workload: dir.join("stack.workload.folded"), + flamegraph_workload: dir.join("flamegraph.workload.svg"), + folded_post: dir.join("stack.post.folded"), + flamegraph_post: dir.join("flamegraph.post.svg"), + folded_focus: dir.join("stack.focus.folded"), + flamegraph_focus: dir.join("flamegraph.focus.svg"), + stack_depth_summary: dir.join("stack-depth-summary.csv"), + flamegraph_html: dir.join("flamegraph.html"), summary: dir.join("summary.txt"), qemu_config: dir.join("qemu.toml"), + host_time: dir.join("qemu.time.txt"), + host_perf: dir.join("qemu.perf.csv"), + resolve_stats: dir.join("resolve.stats.json"), + window: dir.join("window.json"), + qmp_socket: dir.join("qmp.sock"), + profile_stdout: work_dir.join("profile.stdout"), + profile_stderr: work_dir.join("profile.stderr"), + report_json: work_dir.join("report.json"), + report_md: work_dir.join("report.md"), + hotspots_csv: work_dir.join("hotspots.csv"), + hotspot_categories_csv: work_dir.join("hotspot_categories.csv"), dir, }) } -fn build_qperf_tools(root: &Path) -> anyhow::Result { +fn build_qperf_tools(root: &Path, analyzer_flamegraph: bool) -> anyhow::Result { let manifest = root.join("tools/qperf/Cargo.toml"); + let target_dir = root.join("tools/qperf/target"); if !manifest.exists() { bail!( "qperf sources not found at {}; expected tools/qperf to be present", @@ -156,18 +548,27 @@ fn build_qperf_tools(root: &Path) -> anyhow::Result { .args(["build", "--manifest-path"]) .arg(&manifest) .arg("--release") + .arg("--target-dir") + .arg(&target_dir) .exec() .context("failed to build qperf plugin")?; - Command::new("cargo") + let mut analyzer_build = Command::new("cargo"); + analyzer_build .current_dir(root) .args(["build", "--manifest-path"]) - .arg(&manifest) - .args(["--release", "-p", "qperf-analyzer"]) + .arg(root.join("tools/qperf/analyzer/Cargo.toml")) + .arg("--release") + .arg("--target-dir") + .arg(&target_dir); + if analyzer_flamegraph { + analyzer_build.args(["--features", "flamegraph"]); + } + analyzer_build .exec() .context("failed to build qperf-analyzer")?; - let release_dir = root.join("tools/qperf/target/release"); + let release_dir = target_dir.join("release"); let tools = QperfTools { plugin: release_dir.join("libqperf.so"), analyzer: release_dir.join("qperf-analyzer"), @@ -181,88 +582,984 @@ fn write_qemu_config( outputs: &PerfOutputs, tools: &QperfTools, args: &ArgsPerf, + arch: &str, qemu_args: Vec, + text_range: Option, ) -> anyhow::Result<()> { let mut perf_qemu_args = vec!["-plugin".to_string()]; - perf_qemu_args.push(format!( - "{},freq={},max_depth={},queue_size={},out={}", + let mut plugin_params = format!( + "{},freq={},max_depth={},queue_size={},mode={},callchain={},out={}", tools.plugin.display(), args.freq, - args.max_depth, + effective_max_depth(args), QPERF_QUEUE_SIZE, + args.mode, + effective_callchain(args), outputs.raw.display() + ); + plugin_params.push_str(&format!( + ",filter_kernel={}", + if args.kernel_filter { 1 } else { 0 } )); + if let Some(range) = text_range { + let start = range.virt.start; + let end = range.virt.end; + plugin_params.push_str(&format!(",filter_start=0x{start:x},filter_end=0x{end:x}")); + if let Some(phys) = range.phys { + let offset = range.virt.start.wrapping_sub(phys.start); + plugin_params.push_str(&format!( + ",filter_alias_start=0x{:x},filter_alias_end=0x{:x},filter_alias_offset=0x{:x}", + phys.start, phys.end, offset + )); + } + } + perf_qemu_args.push(plugin_params); + let mut qemu_args = direct_qemu_args(arch, qemu_args)?; + qemu_args.extend(args.qemu_args.iter().cloned()); + if qemu_stdout_monitor_enabled(args) && !has_qemu_option(&qemu_args, "-qmp") { + qemu_args.extend([ + "-qmp".to_string(), + format!("unix:{},server=on,wait=off", outputs.qmp_socket.display()), + ]); + } perf_qemu_args.extend(qemu_args); + let shell_init_cmd = args + .shell_init_cmd + .as_deref() + .map(str::trim) + .filter(|cmd| !cmd.is_empty()) + .map(str::to_string); + let shell_prefix = shell_init_cmd.as_ref().map(|_| { + args.shell_prefix + .clone() + .unwrap_or_else(|| DEFAULT_STARRY_SHELL_PREFIX.to_string()) + }); + let config = PerfQemuConfig { args: perf_qemu_args, uefi: false, to_bin: true, success_regex: Vec::new(), fail_regex: vec![r"(?i)\bpanic(?:ked)?\b".to_string()], - shell_prefix: None, - shell_init_cmd: None, + shell_prefix, + shell_init_cmd, timeout: (args.timeout > 0).then_some(args.timeout), + start_marker: args.start_marker.clone(), + stop_marker: args.stop_marker.clone(), + workload_timeout: args.workload_timeout, }; fs::write(&outputs.qemu_config, toml::to_string_pretty(&config)?) .with_context(|| format!("failed to write {}", outputs.qemu_config.display()))?; Ok(()) } +fn direct_qemu_args(arch: &str, mut args: Vec) -> anyhow::Result> { + match arch { + "riscv64" | "loongarch64" => { + if !has_qemu_option(&args, "-machine") { + args.splice(0..0, ["-machine".to_string(), "virt".to_string()]); + } + } + _ => bail!("qperf currently supports StarryOS riscv64 and loongarch64 only"), + } + Ok(args) +} + +fn has_qemu_option(args: &[String], option: &str) -> bool { + args.iter().any(|arg| arg == option) +} + fn run_qemu_direct( outputs: &PerfOutputs, args: &ArgsPerf, arch: &str, kernel_bin: &Path, -) -> anyhow::Result { +) -> anyhow::Result { ensure_file(kernel_bin, "StarryOS kernel image")?; let qemu = qemu_executable(arch)?; - let qemu_args = qemu_args_from_config(&outputs.qemu_config)?; + let config = qemu_config_from_path(&outputs.qemu_config)?; + let qemu_args = config.args.clone(); + let monitor_stdout = qemu_stdout_monitor_enabled(args); - let mut command = if args.timeout > 0 { - let mut command = Command::new("timeout"); - command.arg(format!("{}s", args.timeout)); - command.arg(qemu); - command + let mut command_args = if args.timeout > 0 && !monitor_stdout { + vec![ + "timeout".to_string(), + "--signal=INT".to_string(), + "--kill-after=5s".to_string(), + format!("{}s", args.timeout), + qemu.to_string(), + ] } else { - Command::new(qemu) + vec![qemu.to_string()] }; + command_args.extend(qemu_args); + command_args.push("-kernel".to_string()); + command_args.push(kernel_bin.display().to_string()); + + if args.host_perf { + if let Some(perf) = find_executable("perf") { + let mut wrapped = vec![ + perf.display().to_string(), + "stat".to_string(), + "-x".to_string(), + ",".to_string(), + "-o".to_string(), + outputs.host_perf.display().to_string(), + "-e".to_string(), + args.host_perf_events.clone(), + "--".to_string(), + ]; + wrapped.extend(command_args); + command_args = wrapped; + } else { + write_host_perf_unavailable(&outputs.host_perf, "perf not found in PATH")?; + eprintln!("qperf: --host-perf requested but `perf` was not found in PATH"); + } + } - command.args(qemu_args).arg("-kernel").arg(kernel_bin); + let mut command = Command::new(&command_args[0]); + command.args(&command_args[1..]); eprintln!("running qperf QEMU: {command:?}"); - command.status().context("failed to spawn QEMU") + let host_wall_start = Instant::now(); + let host_usage_start = child_resource_usage(); + let qemu_run = if monitor_stdout { + run_qemu_with_stdout_monitor(command, &config, outputs, args.timeout)? + } else { + QemuRun { + status: command.status().context("failed to spawn QEMU")?, + window: window_report_from_config(&config), + } + }; + if host_time_enabled(args) { + write_host_time_metrics( + &outputs.host_time, + host_wall_start.elapsed(), + host_usage_start, + child_resource_usage(), + &qemu_run.status, + )?; + } + write_window_report(&outputs.window, &qemu_run.window)?; + if !outputs.profile_stdout.exists() { + File::create(&outputs.profile_stdout) + .with_context(|| format!("failed to create {}", outputs.profile_stdout.display()))?; + } + if !outputs.profile_stderr.exists() { + File::create(&outputs.profile_stderr) + .with_context(|| format!("failed to create {}", outputs.profile_stderr.display()))?; + } + Ok(qemu_run) } fn qemu_executable(arch: &str) -> anyhow::Result<&'static str> { - match arch { - "riscv64" => Ok("qemu-system-riscv64"), - "loongarch64" => Ok("qemu-system-loongarch64"), + let name = match arch { + "riscv64" => "qemu-system-riscv64", + "loongarch64" => "qemu-system-loongarch64", _ => bail!("qperf currently supports StarryOS riscv64 and loongarch64 only"), + }; + if find_executable(name).is_none() { + bail!( + "qperf requires `{name}` in PATH; install the matching QEMU system emulator or run \ + the Docker-based harness perf-profile entrypoint" + ); } + Ok(name) } -fn qemu_args_from_config(path: &Path) -> anyhow::Result> { +fn qemu_config_from_path(path: &Path) -> anyhow::Result { let text = fs::read_to_string(path) .with_context(|| format!("failed to read qperf QEMU config {}", path.display()))?; - let config: PerfQemuConfig = toml::from_str(&text) - .with_context(|| format!("failed to parse qperf QEMU config {}", path.display()))?; - Ok(config.args) + toml::from_str(&text) + .with_context(|| format!("failed to parse qperf QEMU config {}", path.display())) +} + +fn qemu_stdout_monitor_enabled(args: &ArgsPerf) -> bool { + args.shell_init_cmd + .as_deref() + .is_some_and(|cmd| !cmd.trim().is_empty()) + || args.start_marker.is_some() + || args.stop_marker.is_some() + || args.workload_timeout.is_some() +} + +fn window_report_from_config(config: &PerfQemuConfig) -> PerfWindowReport { + let enabled = config.start_marker.is_some() + || config.stop_marker.is_some() + || config.workload_timeout.is_some(); + let mut report = PerfWindowReport { + enabled, + start_marker: config.start_marker.clone(), + stop_marker: config.stop_marker.clone(), + workload_timeout: config.workload_timeout, + method: if enabled { + "qperf_raw_elapsed_timestamp_filter".to_string() + } else { + "disabled".to_string() + }, + ..PerfWindowReport::default() + }; + if enabled && config.start_marker.is_none() { + report + .warnings + .push("start marker is not configured; boot samples are not excluded".to_string()); + } + if config.workload_timeout.is_some() && config.start_marker.is_none() { + report + .warnings + .push("--workload-timeout requires a start marker to open the window".to_string()); + } + report +} + +fn run_qemu_with_stdout_monitor( + mut command: Command, + config: &PerfQemuConfig, + outputs: &PerfOutputs, + overall_timeout: u64, +) -> anyhow::Result { + let mut window_report = window_report_from_config(config); + let shell_init_cmd = config + .shell_init_cmd + .as_deref() + .map(str::trim) + .filter(|cmd| !cmd.is_empty()); + if shell_init_cmd.is_some() { + command.stdin(Stdio::piped()); + } + command.stdout(Stdio::piped()); + let mut child = command.spawn().context("failed to spawn QEMU")?; + let mut stdin = child.stdin.take(); + let stdout = child.stdout.take().context("failed to open QEMU stdout")?; + let (tx, rx) = mpsc::channel(); + thread::spawn(move || { + let mut stdout = BufReader::new(stdout); + let mut buf = [0_u8; 1024]; + loop { + match stdout.read(&mut buf) { + Ok(0) => break, + Ok(len) => { + if tx.send(buf[..len].to_vec()).is_err() { + break; + } + } + Err(_) => break, + } + } + }); + + let started = Instant::now(); + let mut host_stdout = std::io::stdout().lock(); + let mut profile_stdout = File::create(&outputs.profile_stdout) + .with_context(|| format!("failed to create {}", outputs.profile_stdout.display()))?; + let mut prompt_window = Vec::new(); + let mut marker_window = Vec::new(); + let mut injected = false; + let mut echo_disable_deadline = None; + let shell_prefix = config + .shell_prefix + .as_deref() + .unwrap_or(DEFAULT_STARRY_SHELL_PREFIX); + let prefix = shell_prefix.as_bytes(); + let start_marker = config.start_marker.as_deref().map(str::as_bytes); + let stop_marker = config.stop_marker.as_deref().map(str::as_bytes); + let marker_monitoring = start_marker.is_some() || stop_marker.is_some(); + + loop { + if let Some(status) = child.try_wait().context("failed to poll QEMU")? { + if shell_init_cmd.is_some() && !injected { + window_report.warnings.push(format!( + "shell prompt `{shell_prefix}` was not observed before QEMU exited" + )); + eprintln!( + "qperf: shell prompt `{shell_prefix}` was not observed before QEMU exited" + ); + } + finalize_window_warnings(&mut window_report); + return Ok(QemuRun { + status, + window: window_report, + }); + } + + match rx.recv_timeout(Duration::from_millis(50)) { + Ok(chunk) => { + profile_stdout + .write_all(&chunk) + .context("failed to write qperf profile stdout")?; + host_stdout + .write_all(&chunk) + .context("failed to forward QEMU stdout")?; + host_stdout.flush().ok(); + let elapsed = started.elapsed().as_secs_f64(); + + if let Some(cmd) = shell_init_cmd + && !injected + && echo_disable_deadline.is_none() + { + prompt_window.extend_from_slice(&chunk); + trim_window(&mut prompt_window, prefix.len().saturating_add(1024)); + if contains_subslice(&prompt_window, prefix) { + let stdin = stdin.as_mut().context("failed to open QEMU stdin")?; + if marker_monitoring { + stdin + .write_all(b"stty -echo 2>/dev/null || true\n") + .context("failed to disable shell echo before qperf command")?; + stdin.flush().ok(); + echo_disable_deadline = + Some(Instant::now() + Duration::from_millis(150)); + } else { + write_shell_init_command(stdin, cmd)?; + injected = true; + eprintln!( + "qperf: injected shell init command after prompt `{shell_prefix}`" + ); + } + } + } + + if start_marker.is_some() || stop_marker.is_some() { + marker_window.extend_from_slice(&chunk); + let keep = start_marker + .into_iter() + .chain(stop_marker) + .map(<[u8]>::len) + .max() + .unwrap_or(0) + .saturating_add(1024); + trim_window(&mut marker_window, keep); + } + + if window_report.start_time.is_none() + && start_marker.is_some_and(|marker| contains_subslice(&marker_window, marker)) + { + window_report.start_time = Some(elapsed); + eprintln!( + "qperf: observed start marker `{}` at {elapsed:.6}s", + config.start_marker.as_deref().unwrap_or("") + ); + } + if window_report.stop_time.is_none() + && stop_marker.is_some_and(|marker| contains_subslice(&marker_window, marker)) + { + window_report.stop_time = Some(elapsed); + update_window_duration(&mut window_report); + request_qemu_stop(&mut child, outputs, &mut window_report, "stop marker")?; + break; + } + } + Err(mpsc::RecvTimeoutError::Timeout) => {} + Err(mpsc::RecvTimeoutError::Disconnected) => {} + } + + if let (Some(cmd), Some(deadline)) = (shell_init_cmd, echo_disable_deadline) + && !injected + && Instant::now() >= deadline + { + let stdin = stdin.as_mut().context("failed to open QEMU stdin")?; + write_shell_init_command(stdin, cmd)?; + injected = true; + echo_disable_deadline = None; + eprintln!("qperf: injected shell init command after prompt `{shell_prefix}`"); + } + + let elapsed = started.elapsed().as_secs_f64(); + if let (Some(start_time), Some(timeout)) = + (window_report.start_time, config.workload_timeout) + && window_report.stop_time.is_none() + && elapsed - start_time >= timeout as f64 + { + window_report.stop_time = Some(elapsed); + window_report.truncated_by_timeout = true; + update_window_duration(&mut window_report); + window_report.warnings.push(format!( + "workload window timed out after {timeout}s without stop marker" + )); + request_qemu_stop(&mut child, outputs, &mut window_report, "workload timeout")?; + break; + } + if overall_timeout > 0 && elapsed >= overall_timeout as f64 { + window_report.warnings.push(format!( + "QEMU timed out after {overall_timeout}s before workload completed" + )); + request_qemu_stop(&mut child, outputs, &mut window_report, "overall timeout")?; + break; + } + } + + let status = wait_for_child_exit(&mut child, Duration::from_secs(20))?; + if shell_init_cmd.is_some() && !injected { + window_report.warnings.push(format!( + "shell prompt `{shell_prefix}` was not observed before QEMU exited" + )); + eprintln!("qperf: shell prompt `{shell_prefix}` was not observed before QEMU exited"); + } + finalize_window_warnings(&mut window_report); + Ok(QemuRun { + status, + window: window_report, + }) +} + +fn trim_window(window: &mut Vec, keep: usize) { + if window.len() > keep { + let drain = window.len() - keep; + window.drain(..drain); + } +} + +fn write_shell_init_command(stdin: &mut impl Write, cmd: &str) -> anyhow::Result<()> { + stdin + .write_all(cmd.as_bytes()) + .context("failed to write qperf shell init command")?; + stdin + .write_all(b"\n") + .context("failed to terminate qperf shell init command")?; + stdin.flush().ok(); + Ok(()) +} + +fn update_window_duration(report: &mut PerfWindowReport) { + report.duration_sec = match (report.start_time, report.stop_time) { + (Some(start), Some(stop)) if stop >= start => Some(stop - start), + _ => None, + }; +} + +fn request_qemu_stop( + child: &mut std::process::Child, + outputs: &PerfOutputs, + report: &mut PerfWindowReport, + reason: &str, +) -> anyhow::Result<()> { + if report.stop_requested { + return Ok(()); + } + report.stop_requested = true; + match request_qmp_quit(&outputs.qmp_socket) { + Ok(()) => { + report.stop_method = Some("qmp_quit".to_string()); + eprintln!("qperf: requested QEMU quit via QMP after {reason}"); + } + Err(err) => { + report.warnings.push(format!( + "QMP quit failed after {reason}: {err}; falling back to SIGINT" + )); + interrupt_child(child)?; + report.stop_method = Some("sigint".to_string()); + eprintln!("qperf: sent SIGINT to QEMU after {reason}"); + } + } + Ok(()) +} + +#[cfg(unix)] +fn request_qmp_quit(socket: &Path) -> anyhow::Result<()> { + use std::os::unix::net::UnixStream; + + let mut stream = UnixStream::connect(socket) + .with_context(|| format!("failed to connect QMP socket {}", socket.display()))?; + stream + .set_read_timeout(Some(Duration::from_millis(200))) + .ok(); + stream + .set_write_timeout(Some(Duration::from_millis(200))) + .ok(); + let mut buf = [0_u8; 512]; + let _ = stream.read(&mut buf); + stream.write_all(b"{\"execute\":\"qmp_capabilities\"}\r\n")?; + let _ = stream.read(&mut buf); + stream.write_all(b"{\"execute\":\"quit\"}\r\n")?; + stream.flush()?; + Ok(()) +} + +#[cfg(not(unix))] +fn request_qmp_quit(_socket: &Path) -> anyhow::Result<()> { + bail!("QMP unix sockets are not supported on this host") +} + +#[cfg(unix)] +fn interrupt_child(child: &mut std::process::Child) -> anyhow::Result<()> { + let pid = child.id() as libc::pid_t; + if unsafe { libc::kill(pid, libc::SIGINT) } == 0 { + Ok(()) + } else { + Err(std::io::Error::last_os_error()).context("failed to send SIGINT to QEMU") + } } -fn run_analyzer(analyzer: &Path, elf: &Path, raw: &Path, folded: &Path) -> anyhow::Result<()> { - ensure_file(elf, "StarryOS kernel ELF")?; - ensure_file(raw, "qperf raw samples")?; - Command::new(analyzer) +#[cfg(not(unix))] +fn interrupt_child(child: &mut std::process::Child) -> anyhow::Result<()> { + child.kill().context("failed to kill QEMU") +} + +fn wait_for_child_exit( + child: &mut std::process::Child, + timeout: Duration, +) -> anyhow::Result { + let deadline = Instant::now() + timeout; + loop { + if let Some(status) = child.try_wait().context("failed to poll QEMU after stop")? { + return Ok(status); + } + if Instant::now() >= deadline { + child.kill().context("failed to kill unresponsive QEMU")?; + return child.wait().context("failed to wait for killed QEMU"); + } + thread::sleep(Duration::from_millis(50)); + } +} + +fn finalize_window_warnings(report: &mut PerfWindowReport) { + if !report.enabled { + return; + } + if report.start_marker.is_some() && report.start_time.is_none() { + report + .warnings + .push("start marker was not observed; folded stacks include boot samples".to_string()); + } + if report.start_time.is_some() && report.stop_marker.is_some() && report.stop_time.is_none() { + report + .warnings + .push("stop marker was not observed; workload window extends to QEMU exit".to_string()); + } + update_window_duration(report); +} + +fn write_window_report(path: &Path, report: &PerfWindowReport) -> anyhow::Result<()> { + let text = serde_json::to_string_pretty(report).context("failed to serialize qperf window")?; + fs::write(path, text).with_context(|| format!("failed to write {}", path.display())) +} + +fn contains_subslice(haystack: &[u8], needle: &[u8]) -> bool { + needle.is_empty() + || haystack + .windows(needle.len()) + .any(|window| window == needle) +} + +fn write_host_time_metrics( + path: &Path, + elapsed: Duration, + usage_start: Option, + usage_end: Option, + status: &ExitStatus, +) -> anyhow::Result<()> { + let mut file = + File::create(path).with_context(|| format!("failed to create {}", path.display()))?; + let elapsed_seconds = elapsed.as_secs_f64(); + writeln!(file, "Elapsed time: {elapsed_seconds:.6}")?; + if let (Some(start), Some(end)) = (usage_start, usage_end) { + let usage = end.delta_since(start); + let user_seconds = usage.user_seconds(); + let system_seconds = usage.system_seconds(); + writeln!(file, "User time: {user_seconds:.6}")?; + writeln!(file, "System time: {system_seconds:.6}")?; + if elapsed_seconds > 0.0 { + let cpu_percent = (user_seconds + system_seconds) / elapsed_seconds * 100.0; + writeln!(file, "Percent of CPU this job got: {cpu_percent:.2}%")?; + } + writeln!(file, "Major page faults: {}", usage.major_faults)?; + writeln!(file, "Minor page faults: {}", usage.minor_faults)?; + writeln!( + file, + "Voluntary context switches: {}", + usage.voluntary_context_switches + )?; + writeln!( + file, + "Involuntary context switches: {}", + usage.involuntary_context_switches + )?; + } else { + writeln!(file, "User time: unavailable")?; + writeln!(file, "System time: unavailable")?; + } + writeln!(file, "Exit status: {}", exit_status_code(status))?; + Ok(()) +} + +fn write_host_perf_unavailable(path: &Path, reason: &str) -> anyhow::Result<()> { + let mut file = + File::create(path).with_context(|| format!("failed to create {}", path.display()))?; + writeln!(file, "# host perf unavailable: {reason}")?; + writeln!( + file, + "# host perf stat measures the host QEMU process; it is not a guest PMU counter" + )?; + Ok(()) +} + +fn exit_status_code(status: &ExitStatus) -> i32 { + status + .code() + .unwrap_or_else(|| if status.success() { 0 } else { 1 }) +} + +fn nonnegative_delta(after: i128, before: i128) -> i128 { + after.saturating_sub(before).max(0) +} + +#[cfg(unix)] +fn child_resource_usage() -> Option { + let mut usage = std::mem::MaybeUninit::::uninit(); + // SAFETY: getrusage initializes the provided rusage pointer when it returns 0. + if unsafe { libc::getrusage(libc::RUSAGE_CHILDREN, usage.as_mut_ptr()) } != 0 { + return None; + } + // SAFETY: getrusage returned success, so usage is initialized. + let usage = unsafe { usage.assume_init() }; + Some(ChildResourceUsage { + user_micros: timeval_micros(usage.ru_utime), + system_micros: timeval_micros(usage.ru_stime), + major_faults: usage.ru_majflt.into(), + minor_faults: usage.ru_minflt.into(), + voluntary_context_switches: usage.ru_nvcsw.into(), + involuntary_context_switches: usage.ru_nivcsw.into(), + }) +} + +#[cfg(unix)] +fn timeval_micros(value: libc::timeval) -> i128 { + i128::from(value.tv_sec) * 1_000_000 + i128::from(value.tv_usec) +} + +#[cfg(not(unix))] +fn child_resource_usage() -> Option { + None +} + +struct AnalyzerRun<'a> { + analyzer: &'a Path, + elf: &'a Path, + raw: &'a Path, + folded: &'a Path, + flamegraph: &'a Path, + resolve_stats: &'a Path, + depth_summary: Option<&'a Path>, + generate_svg: bool, + top_n: usize, + start_sec: Option, + stop_sec: Option, + symbol_style: String, + demangle: bool, + focus: Option<&'a str>, + min_percent: f64, +} + +fn run_analyzer(args: AnalyzerRun<'_>) -> anyhow::Result<()> { + ensure_file(args.elf, "StarryOS kernel ELF")?; + ensure_file(args.raw, "qperf raw samples")?; + let mut command = Command::new(args.analyzer); + command + .arg("resolve") .arg("-e") - .arg(elf) - .arg(raw) - .arg(folded) - .exec() - .context("failed to run qperf-analyzer")?; - ensure_file(folded, "folded stack output")?; + .arg(args.elf) + .arg(args.raw) + .arg(args.folded); + if args.top_n > 0 { + command.arg("--top").arg(args.top_n.to_string()); + } + if let Some(start_sec) = args.start_sec { + command.arg("--start-sec").arg(format!("{start_sec:.9}")); + } + if let Some(stop_sec) = args.stop_sec { + command.arg("--stop-sec").arg(format!("{stop_sec:.9}")); + } + command + .arg("--symbol-style") + .arg(&args.symbol_style) + .arg("--min-percent") + .arg(args.min_percent.to_string()); + if !args.demangle { + command.arg("--no-demangle"); + } + if let Some(focus) = args.focus { + command.arg("--focus").arg(focus); + } + command.arg("--stats").arg(args.resolve_stats); + if let Some(depth_summary) = args.depth_summary { + command.arg("--depth-summary").arg(depth_summary); + } + if args.generate_svg { + command.arg("--flamegraph").arg(args.flamegraph); + } + command.exec().context("failed to run qperf-analyzer")?; + if !args.folded.exists() { + bail!("folded stack output not found at {}", args.folded.display()); + } + Ok(()) +} + +fn generate_phase_flamegraphs( + tools: &QperfTools, + elf: &Path, + outputs: &PerfOutputs, + args: &ArgsPerf, + window: &PerfWindowReport, + generate_svg: bool, +) -> anyhow::Result<()> { + if window.start_time.is_some() && window.stop_time.is_some() { + fs::copy(&outputs.folded, &outputs.folded_workload).with_context(|| { + format!( + "failed to copy workload folded stack to {}", + outputs.folded_workload.display() + ) + })?; + if file_nonempty(&outputs.flamegraph) { + fs::copy(&outputs.flamegraph, &outputs.flamegraph_workload).with_context(|| { + format!( + "failed to copy workload flamegraph to {}", + outputs.flamegraph_workload.display() + ) + })?; + } + } + if let Some(start_sec) = window.start_time { + run_analyzer(AnalyzerRun { + analyzer: &tools.analyzer, + elf, + raw: &outputs.raw, + folded: &outputs.folded_boot, + flamegraph: &outputs.flamegraph_boot, + resolve_stats: &outputs + .resolve_stats + .with_file_name("resolve.boot.stats.json"), + depth_summary: Some( + &outputs + .stack_depth_summary + .with_file_name("stack-depth-summary.boot.csv"), + ), + generate_svg, + top_n: 0, + start_sec: None, + stop_sec: Some(start_sec), + symbol_style: args.symbol_style.to_string(), + demangle: true, + focus: None, + min_percent: flamegraph_min_percent(args), + })?; + } + if let Some(stop_sec) = window.stop_time { + run_analyzer(AnalyzerRun { + analyzer: &tools.analyzer, + elf, + raw: &outputs.raw, + folded: &outputs.folded_post, + flamegraph: &outputs.flamegraph_post, + resolve_stats: &outputs + .resolve_stats + .with_file_name("resolve.post.stats.json"), + depth_summary: Some( + &outputs + .stack_depth_summary + .with_file_name("stack-depth-summary.post.csv"), + ), + generate_svg, + top_n: 0, + start_sec: Some(stop_sec), + stop_sec: None, + symbol_style: args.symbol_style.to_string(), + demangle: true, + focus: None, + min_percent: flamegraph_min_percent(args), + })?; + } + Ok(()) +} + +fn generate_focus_flamegraph( + tools: &QperfTools, + elf: &Path, + outputs: &PerfOutputs, + args: &ArgsPerf, + generate_svg: bool, +) -> anyhow::Result<()> { + let Some(focus) = args.focus.as_deref() else { + return Ok(()); + }; + run_analyzer(AnalyzerRun { + analyzer: &tools.analyzer, + elf, + raw: &outputs.raw, + folded: &outputs.folded_focus, + flamegraph: &outputs.flamegraph_focus, + resolve_stats: &outputs + .resolve_stats + .with_file_name("resolve.focus.stats.json"), + depth_summary: Some( + &outputs + .stack_depth_summary + .with_file_name("stack-depth-summary.focus.csv"), + ), + generate_svg, + top_n: 0, + start_sec: None, + stop_sec: None, + symbol_style: args.symbol_style.to_string(), + demangle: true, + focus: Some(focus), + min_percent: flamegraph_min_percent(args), + }) +} + +fn write_flamegraph_html( + outputs: &PerfOutputs, + kind: PerfFlamegraphKind, + flamegraph_generated: bool, +) -> anyhow::Result<()> { + if !matches!(kind, PerfFlamegraphKind::Html) || !flamegraph_generated { + return Ok(()); + } + let svg = outputs + .flamegraph + .file_name() + .and_then(|name| name.to_str()) + .unwrap_or("flamegraph.svg"); + let html = format!( + "StarryOS qperf Flame \ + Graph