Skip to content

Commit 04c05d7

Browse files
branchseerbranchseer
authored
feat: show saved time in summary (#187)
# feat: show saved time in summary This PR adds duration tracking to task execution and displays time saved from cache hits in the UI. When a task is executed from cache, it now shows how much time was saved from the original execution. The summary also displays the total time saved across all cache hits. The changes include: - Track execution duration for each task - Store duration in the cache along with other task data - Display individual task duration savings in the UI - Show total time saved in the performance summary - Update database schema version to support the new duration field
1 parent 3a69079 commit 04c05d7

18 files changed

Lines changed: 114 additions & 65 deletions

File tree

‎crates/vite_task/src/cache.rs‎

Lines changed: 18 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,8 @@
1-
use std::{fmt::Display, io::Write, sync::Arc};
1+
use std::{fmt::Display, io::Write, sync::Arc, time::Duration};
22

33
// use bincode::config::{Configuration, standard};
44
use bincode::{Decode, Encode, decode_from_slice, encode_to_vec};
5-
use rusqlite::{Connection, OptionalExtension as _};
5+
use rusqlite::{Connection, OptionalExtension as _, config::DbConfig};
66
use serde::{Deserialize, Serialize};
77
use tokio::sync::Mutex;
88
use vite_path::{AbsolutePath, AbsolutePathBuf};
@@ -22,6 +22,7 @@ use crate::{
2222
pub struct CommandCacheValue {
2323
pub post_run_fingerprint: PostRunFingerprint,
2424
pub std_outputs: Arc<[StdOutput]>,
25+
pub duration: Duration,
2526
}
2627

2728
impl CommandCacheValue {
@@ -31,7 +32,11 @@ impl CommandCacheValue {
3132
base_dir: &AbsolutePath,
3233
) -> Result<Self, Error> {
3334
let post_run_fingerprint = PostRunFingerprint::create(&executed_task, fs, base_dir)?;
34-
Ok(Self { post_run_fingerprint, std_outputs: executed_task.std_outputs })
35+
Ok(Self {
36+
post_run_fingerprint,
37+
std_outputs: executed_task.std_outputs,
38+
duration: executed_task.duration,
39+
})
3540
}
3641
}
3742

@@ -86,7 +91,7 @@ impl TaskCache {
8691

8792
let db_path = path.join("cache.db");
8893
let conn = Connection::open(db_path.as_path())?;
89-
conn.execute_batch("PRAGMA journal_mode=WAL; BEGIN EXCLUSIVE;")?;
94+
conn.execute_batch("PRAGMA journal_mode=WAL;")?;
9095
loop {
9196
let user_version: u32 = conn.query_one("PRAGMA user_version", (), |row| row.get(0))?;
9297
match user_version {
@@ -100,13 +105,18 @@ impl TaskCache {
100105
"CREATE TABLE taskrun_to_command (key BLOB PRIMARY KEY, value BLOB);",
101106
(),
102107
)?;
103-
conn.execute("PRAGMA user_version = 1", ())?;
108+
conn.execute("PRAGMA user_version = 2", ())?;
104109
}
105-
1 => break, // current version
106-
2.. => return Err(Error::UnrecognizedDbVersion(user_version)),
110+
1 => {
111+
// old internal db version. reset
112+
conn.set_db_config(DbConfig::SQLITE_DBCONFIG_RESET_DATABASE, true)?;
113+
conn.execute("VACUUM", ())?;
114+
conn.set_db_config(DbConfig::SQLITE_DBCONFIG_RESET_DATABASE, false)?;
115+
}
116+
2 => break, // current version
117+
3.. => return Err(Error::UnrecognizedDbVersion(user_version)),
107118
}
108119
}
109-
conn.execute_batch("COMMIT")?;
110120
Ok(Self { conn: Mutex::new(conn), path: cache_path })
111121
}
112122

‎crates/vite_task/src/execute.rs‎

Lines changed: 18 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ use std::{
55
path::PathBuf,
66
process::{ExitStatus, Stdio},
77
sync::{Arc, LazyLock, Mutex},
8+
time::{Duration, Instant},
89
};
910

1011
use bincode::{Decode, Encode};
@@ -53,6 +54,7 @@ pub struct ExecutedTask {
5354
pub exit_status: ExitStatus,
5455
pub path_reads: HashMap<RelativePathBuf, PathRead>,
5556
pub path_writes: HashMap<RelativePathBuf, PathWrite>,
57+
pub duration: Duration,
5658
}
5759

5860
/// Collects stdout/stderr into `outputs` and at the same time writes them to the real stdout/stderr
@@ -371,17 +373,24 @@ pub async fn execute_task(
371373
let child_stderr = child.stderr.take().unwrap();
372374

373375
let outputs = Mutex::new(Vec::<StdOutput>::new());
374-
let ((), (), exit_status) = try_join3(
376+
377+
let ((), (), (exit_status, duration)) = try_join3(
375378
collect_std_outputs(&outputs, child_stdout, OutputKind::StdOut),
376379
collect_std_outputs(&outputs, child_stderr, OutputKind::StdErr),
377-
async move { Ok(child.wait().await?) },
380+
async move {
381+
let start = Instant::now();
382+
let exit_status = child.wait().await?;
383+
Ok((exit_status, start.elapsed()))
384+
},
378385
)
379386
.await?;
387+
380388
return Ok(ExecutedTask {
381389
std_outputs: outputs.into_inner().unwrap().into(),
382390
exit_status,
383391
path_reads: HashMap::new(),
384392
path_writes: HashMap::new(),
393+
duration,
385394
});
386395
}
387396
let mut cmd = spy.new_command(&task_parsed_command.program);
@@ -451,11 +460,15 @@ pub async fn execute_task(
451460
Ok::<_, Error>((path_reads, path_writes))
452461
};
453462

454-
let ((), (), (path_reads, path_writes), exit_status) = try_join4(
463+
let ((), (), (path_reads, path_writes), (exit_status, duration)) = try_join4(
455464
collect_std_outputs(&outputs, child_stdout, OutputKind::StdOut),
456465
collect_std_outputs(&outputs, child_stderr, OutputKind::StdErr),
457466
path_accesses_fut,
458-
async move { Ok(child.wait().await?) },
467+
async move {
468+
let start = Instant::now();
469+
let exit_status = child.wait().await?;
470+
Ok((exit_status, start.elapsed()))
471+
},
459472
)
460473
.await?;
461474

@@ -470,7 +483,7 @@ pub async fn execute_task(
470483

471484
// let input_paths = gather_inputs(task, base_dir)?;
472485

473-
Ok(ExecutedTask { std_outputs: outputs.into(), exit_status, path_reads, path_writes })
486+
Ok(ExecutedTask { std_outputs: outputs.into(), exit_status, path_reads, path_writes, duration })
474487
}
475488

476489
#[expect(dead_code)]

‎crates/vite_task/src/schedule.rs‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
use std::{process::ExitStatus, sync::Arc};
1+
use std::{process::ExitStatus, sync::Arc, time::Duration};
22

33
use futures_core::future::BoxFuture;
44
use futures_util::future::FutureExt as _;
@@ -39,7 +39,10 @@ pub enum CacheStatus {
3939
/// The task will be executed.
4040
CacheMiss(CacheMiss),
4141
/// Cache hit, will replay
42-
CacheHit,
42+
CacheHit {
43+
/// Duration of the original execution
44+
original_duration: Duration,
45+
},
4346
}
4447

4548
/// Status of a task execution
@@ -184,7 +187,7 @@ async fn get_cached_or_execute<'a>(
184187
) -> Result<(CacheStatus, BoxFuture<'a, Result<ExitStatus, Error>>), Error> {
185188
Ok(match cache.try_hit(&task, fs, base_dir).await? {
186189
Ok(cache_task) => (
187-
CacheStatus::CacheHit,
190+
CacheStatus::CacheHit { original_duration: cache_task.duration },
188191
({
189192
async move {
190193
if task.display_options.ignore_replay {

‎crates/vite_task/src/ui.rs‎

Lines changed: 31 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
use std::{fmt::Display, sync::LazyLock};
1+
use std::{fmt::Display, sync::LazyLock, time::Duration};
22

33
use itertools::Itertools;
44
use owo_colors::{Style, Styled};
@@ -101,7 +101,7 @@ impl Display for PreExecutionStatus {
101101
.style(CACHE_MISS_STYLE.dimmed())
102102
)?;
103103
}
104-
CacheStatus::CacheHit => {
104+
CacheStatus::CacheHit { .. } => {
105105
if !self.display_options.ignore_replay {
106106
if let Some(display_command) = &display_command {
107107
write!(f, "{} ", display_command)?;
@@ -141,7 +141,7 @@ impl Display for ExecutionSummary {
141141

142142
for status in &self.execution_statuses {
143143
match &status.pre_execution_status.cache_status {
144-
CacheStatus::CacheHit => cache_hits += 1,
144+
CacheStatus::CacheHit { .. } => cache_hits += 1,
145145
CacheStatus::CacheMiss(_) => cache_misses += 1,
146146
}
147147

@@ -191,18 +191,40 @@ impl Display for ExecutionSummary {
191191
let cache_rate =
192192
if total > 0 { (cache_hits as f64 / total as f64 * 100.0) as u32 } else { 0 };
193193

194-
writeln!(
194+
let total_duration = self
195+
.execution_statuses
196+
.iter()
197+
.map(|status| {
198+
if let CacheStatus::CacheHit { original_duration } =
199+
&status.pre_execution_status.cache_status
200+
{
201+
*original_duration
202+
} else {
203+
Duration::ZERO
204+
}
205+
})
206+
.sum::<std::time::Duration>();
207+
208+
write!(
195209
f,
196-
"{} {}% cache hit rate",
210+
"{} {} cache hit rate",
197211
"Performance:".style(Style::new().bold()),
198-
cache_rate.to_string().style(if cache_rate >= 75 {
212+
format_args!("{}%", cache_rate).style(if cache_rate >= 75 {
199213
Style::new().green().bold()
200214
} else if cache_rate >= 50 {
201215
CACHE_MISS_STYLE
202216
} else {
203217
Style::new().red()
204218
})
205219
)?;
220+
if total_duration > Duration::ZERO {
221+
write!(
222+
f,
223+
", {:.2?} saved in total",
224+
total_duration.style(Style::new().green().bold())
225+
)?;
226+
}
227+
writeln!(f)?;
206228
writeln!(f)?;
207229

208230
// Detailed task results
@@ -254,11 +276,12 @@ impl Display for ExecutionSummary {
254276

255277
// Cache status details (indented)
256278
match &status.pre_execution_status.cache_status {
257-
CacheStatus::CacheHit => {
279+
CacheStatus::CacheHit { original_duration } => {
258280
writeln!(
259281
f,
260-
" {}",
282+
" {} {}",
261283
"→ Cache hit - output replayed".style(Style::new().green()),
284+
format!("- {:.2?} saved", original_duration).style(Style::new().green())
262285
)?;
263286
}
264287
CacheStatus::CacheMiss(miss) => {

‎packages/cli/snap-tests/associate-existing-cache/snap.txt‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,12 +26,12 @@ hello
2626
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
2727

2828
Statistics: 1 tasks • 1 cache hits • 0 cache misses
29-
Performance: 100% cache hit rate
29+
Performance: 100% cache hit rate, <variable>ms saved in total
3030

3131
Task Details:
3232
────────────────────────────────────────────────
3333
[1] script2: $ echo hello ✓
34-
→ Cache hit - output replayed
34+
→ Cache hit - output replayed - <variable>ms saved
3535
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
3636

3737
> json-edit package.json '_.scripts.script2 = "echo world"' # update the command of script2

‎packages/cli/snap-tests/cache-clean/snap.txt‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,12 +26,12 @@ hello
2626
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
2727

2828
Statistics: 1 tasks • 1 cache hits • 0 cache misses
29-
Performance: 100% cache hit rate
29+
Performance: 100% cache hit rate, <variable>ms saved in total
3030

3131
Task Details:
3232
────────────────────────────────────────────────
3333
[1] hello: $ echo hello ✓
34-
→ Cache hit - output replayed
34+
→ Cache hit - output replayed - <variable>ms saved
3535
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
3636

3737
> vite cache clean # clean the cache

‎packages/cli/snap-tests/cache-miss-command-change/snap.txt‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -36,15 +36,15 @@ bar
3636
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
3737

3838
Statistics: 2 tasks • 1 cache hits • 1 cache misses
39-
Performance: 50% cache hit rate
39+
Performance: 50% cache hit rate, <variable>ms saved in total
4040

4141
Task Details:
4242
────────────────────────────────────────────────
4343
[1] hello(subcommand 0): $ echo baz ✓
4444
→ Cache miss: command changed from echo foo to echo baz
4545
·······················································
4646
[2] hello: $ echo bar ✓
47-
→ Cache hit - output replayed
47+
→ Cache hit - output replayed - <variable>ms saved
4848
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
4949

5050
> json-edit package.json '_.scripts.hello = "echo bar"' # remove the first subcommand, now the second subcommand becomes the first
@@ -58,10 +58,10 @@ bar
5858
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
5959

6060
Statistics: 1 tasks • 1 cache hits • 0 cache misses
61-
Performance: 100% cache hit rate
61+
Performance: 100% cache hit rate, <variable>ms saved in total
6262

6363
Task Details:
6464
────────────────────────────────────────────────
6565
[1] hello: $ echo bar ✓
66-
→ Cache hit - output replayed
66+
→ Cache hit - output replayed - <variable>ms saved
6767
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━

‎packages/cli/snap-tests/change-passthrough-env-config/snap.txt‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,12 +26,12 @@ $ node -p process.env.MY_ENV (✓ cache hit, replaying)
2626
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
2727

2828
Statistics: 1 tasks • 1 cache hits • 0 cache misses
29-
Performance: 100% cache hit rate
29+
Performance: 100% cache hit rate, <variable>ms saved in total
3030

3131
Task Details:
3232
────────────────────────────────────────────────
3333
[1] hello: $ node -p process.env.MY_ENV ✓
34-
→ Cache hit - output replayed
34+
→ Cache hit - output replayed - <variable>ms saved
3535
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
3636

3737
> json-edit vite-task.json '_.tasks.hello.passThroughEnvs.push("MY_ENV2")' # add a new pass through env

‎packages/cli/snap-tests/exit-code/snap.txt‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,12 +26,12 @@ success
2626
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
2727

2828
Statistics: 1 tasks • 1 cache hits • 0 cache misses
29-
Performance: 100% cache hit rate
29+
Performance: 100% cache hit rate, <variable>ms saved in total
3030

3131
Task Details:
3232
────────────────────────────────────────────────
3333
[1] script1: $ echo success ✓
34-
→ Cache hit - output replayed
34+
→ Cache hit - output replayed - <variable>ms saved
3535
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
3636

3737
[1]> vite run script2 # script2 should be failure and not cache

‎packages/cli/snap-tests/individual-cache-for-adt-args/snap.txt‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -44,12 +44,12 @@ a
4444
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
4545

4646
Statistics: 1 tasks • 1 cache hits • 0 cache misses
47-
Performance: 100% cache hit rate
47+
Performance: 100% cache hit rate, <variable>ms saved in total
4848

4949
Task Details:
5050
────────────────────────────────────────────────
5151
[1] echo: $ echo a ✓
52-
→ Cache hit - output replayed
52+
→ Cache hit - output replayed - <variable>ms saved
5353
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
5454

5555
> vite run echo -- b # should hit the cache created in step 2
@@ -62,10 +62,10 @@ b
6262
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
6363

6464
Statistics: 1 tasks • 1 cache hits • 0 cache misses
65-
Performance: 100% cache hit rate
65+
Performance: 100% cache hit rate, <variable>ms saved in total
6666

6767
Task Details:
6868
────────────────────────────────────────────────
6969
[1] echo: $ echo b ✓
70-
→ Cache hit - output replayed
70+
→ Cache hit - output replayed - <variable>ms saved
7171
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━

0 commit comments

Comments
 (0)