feat(cache): log persistent cache read and write timings#14314
feat(cache): log persistent cache read and write timings#14314hardfist wants to merge 3 commits into
Conversation
Emit info-level durations for persistent cache recovery, staging, and flush so builds with stats.logging can see where cache I/O time is spent. Fixes #14102
Deploying rspack with
|
| Latest commit: |
f9ae58c
|
| Status: | ✅ Deploy successful! |
| Preview URL: | https://78f2b628.rspack-v2.pages.dev |
| Branch Preview URL: | https://cursor-574f5e6d.rspack-v2.pages.dev |
📦 Binary Size-limit
❌ Size increased by 4.00KB from 62.60MB to 62.60MB (⬆️0.01%) |
Rsdoctor Bundle Diff AnalysisFound 5 projects in monorepo, 5 projects with changes. 📊 Quick Summary
📋 Detailed Reports (Click to expand)📁 popular-libsPath:
📁 react-10kPath:
📁 react-1kPath:
📁 react-5kPath:
📁 ui-componentsPath:
Generated by Rsdoctor GitHub Action |
Merging this PR will not alter performance
|
|
@codspeed explain regression |
Regression analysisShort version: the two flagged benchmarks are not affected by the code in this PR — the ~3% deltas are measurement noise, not a real regression. What this PR changesThe only Rust change is in What regressed
Neither of these benchmarks exercises the persistent cache. I re-rooted the flamegraph for Why the numbers moved anywayThe CodSpeed comment itself flags two confounders:
Combined with the small magnitude (~0.2 ms, roughly run-to-run jitter for a Simulation benchmark), this is consistent with noise rather than a code-caused regression. RecommendationNo code change is needed for this — the cache-timing logs can't slow down hash/export benchmarks that never touch the cache. You can safely acknowledge these two benchmarks on CodSpeed. If you'd like a cleaner comparison, re-running once a successful Summary
Was this response helpful? React with 👍 or 👎 to help us improve CodSpeedBot. |
There was a problem hiding this comment.
Pull request overview
This PR adds info-level timing logs for persistent cache read/write phases to help explain “missing” wall-clock time when persistent cache is enabled (Fixes #14102), and updates docs/tests to reflect the new log output.
Changes:
- Add per-phase timing logs in
CacheContextfor build dependency validation, snapshot restore, occasion recovery/save, staging, and disk flush. - Normalize duration output in cache-case stats snapshot matching and update many cache-case snapshots accordingly.
- Document the new timing logs in the persistent cache configuration docs (EN + ZH).
Reviewed changes
Copilot reviewed 123 out of 123 changed files in this pull request and generated 4 comments.
Show a summary per file
| File | Description |
|---|---|
| crates/rspack_core/src/cache/persistent/context.rs | Adds timing instrumentation logs around persistent cache load/save/stage/flush phases. |
| packages/rspack-test-tools/src/case/cache.ts | Normalizes xx ms placeholders by replacing numeric millisecond durations in stats output. |
| website/docs/en/config/cache.mdx | Documents that persistent cache logs now include phase read/write timing information. |
| website/docs/zh/config/cache.mdx | Same as EN docs; explains timing logs for each cache phase in Chinese. |
| tests/rspack-test/cacheCases/storage/directory/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/storage/directory/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/storage/directory/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/storage/directory/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/unmanaged-paths/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/unmanaged-paths/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/unmanaged-paths/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/unmanaged-paths/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/missing_dependencies/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/missing_dependencies/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/managed-paths/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/managed-paths/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/managed-paths/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/managed-paths/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/immutable-paths/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/immutable-paths/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/immutable-paths/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/immutable-paths/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/default_value/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/default_value/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/default_value/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/default_value/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/context-dependencies/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/context-dependencies/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/snapshot/context-dependencies/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/portable/basic/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/portable/basic/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/portable/basic/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/mf/issue-9150/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/mf/issue-9150/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/mf/issue-9150/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/mf/issue-9150/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/refactorize_dep/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/refactorize_dep/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/refactorize_dep/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/provide-plugin/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/provide-plugin/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/provide-plugin/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/provide-plugin/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/lazy-barrel/snapshots/stats-5.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/keep-module-error/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/keep-module-error/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/issuer-update/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/issuer-update/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/issuer-update/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/isolated_module/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/isolated_module/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/isolated_module/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/isolated_module/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/define-plugin/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/define-plugin/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/define-plugin/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/make/define-plugin/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/lib-symlink/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/lib-symlink/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-name/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-name/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-name/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-name/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-mode/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-mode/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-mode/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/invalidation/config-mode/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/version/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/version/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/version/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/version/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/update-file/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/update-file/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/update-file/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/update-file/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/update-file/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/rstest-virtual-module-mock-build-cache/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/rstest-virtual-module-mock-build-cache/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/readonly/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/readonly/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/readonly/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/readonly/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/readonly/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/module-asset/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/module-asset/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/module-asset/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/module-asset/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/minimize-cache/snapshots/stats-5.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies/snapshots/stats-5.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-5.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-resolve/snapshots/stats-6.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-4.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-5.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-6.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/build-dependencies-dir/snapshots/stats-7.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/basic/snapshots/stats-0.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/basic/snapshots/stats-1.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/basic/snapshots/stats-2.txt | Updates expected persistent cache timing logs in stats snapshot. |
| tests/rspack-test/cacheCases/common/basic/snapshots/stats-3.txt | Updates expected persistent cache timing logs in stats snapshot. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| // load_failed: reset snapshot scopes so they are fully rewritten this build. | ||
| if !self.readonly { | ||
| snapshot.reset(&mut *self.storage); | ||
| } | ||
| log_read_timing(self.logger(), "snapshot", start); | ||
| None |
| @@ -233,6 +251,7 @@ | |||
| if !self.readonly { | |||
| occasion.reset(&mut *self.storage); | |||
| } | |||
| log_read_timing(self.logger(), occasion.name(), start); | |||
| None | |||
| log_write_timing( | ||
| self.logger(), | ||
| &format!("{} persistent cache", occasion.name()), | ||
| start, | ||
| ); |
| ``` | ||
|
|
||
| 日志会包含持久化缓存的关键信息,例如持久化缓存是否启用、构建依赖是否有效、缓存恢复是否成功,以及持久化缓存失效的原因,同时也会包含其他 logger 的日志。 | ||
| 日志会包含持久化缓存的关键信息,例如持久化缓存是否启用、构建依赖是否有效、缓存恢复是否成功,以及持久化缓存失效的原因。日志还会包含各缓存阶段的读写耗时(例如构建依赖校验、快照恢复、occasion 恢复、暂存以及刷盘)。同时也会包含其他 logger 的日志。 |
Summary
Related links
Fixes #14102
Checklist
Test plan
cargo test -p rspack_core cache::cd tests/rspack-test && pnpm run test -t "cacheCases"