Skip to content

update(turbopack): Update the messaging UX for timing writing files to disk #79469

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 6 additions & 13 deletions crates/napi/src/next_api/project.rs
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ use turbo_rcstr::RcStr;
use turbo_tasks::{
Completion, Effects, FxIndexSet, OperationVc, ReadRef, ResolvedVc, TransientInstance,
TryJoinIterExt, UpdateInfo, Vc, get_effects,
message_queue::{CompilationEvent, DiagnosticEvent, Severity},
message_queue::{CompilationEvent, DiagnosticEvent, Severity, TimingEvent},
};
use turbo_tasks_fs::{
DiskFileSystem, FileContent, FileSystem, FileSystemPath, get_relative_path_to,
Expand Down Expand Up @@ -405,8 +405,8 @@ pub async fn project_new(
)?;

turbo_tasks.send_compilation_event(Arc::new(DiagnosticEvent::new(
"Starting the compilation events server...".to_owned(),
Severity::Trace,
Severity::Info,
"Starting the compilation events server ...".to_owned(),
)));

let stats_path = std::env::var_os("NEXT_TURBOPACK_TASK_STATISTICS");
Expand Down Expand Up @@ -850,21 +850,14 @@ pub async fn project_write_all_entrypoints_to_disk(

// Start timing writing the files to disk
let now = Instant::now();
compilation_event_sender.send_compilation_event(Arc::new(DiagnosticEvent::new(
"Starting to write all entrypoints to disk...".to_owned(),
Severity::Event,
)));

// Write the files to disk
effects.apply().await?;

// Send a compilation event to indicate that the files have been written to disk
compilation_event_sender.send_compilation_event(Arc::new(DiagnosticEvent::new(
format!(
"Finished writing all entrypoints to disk in {:?}",
now.elapsed()
),
Severity::Event,
compilation_event_sender.send_compilation_event(Arc::new(TimingEvent::new(
"Finished writing all entrypoints to disk".to_owned(),
now.elapsed(),
)));

Ok((entrypoints.clone(), issues.clone(), diagnostics.clone()))
Expand Down
23 changes: 21 additions & 2 deletions packages/next/src/build/turbopack-build/impl.ts
Original file line number Diff line number Diff line change
Expand Up @@ -91,8 +91,27 @@ export async function turbopackBuild(): Promise<{
try {
;(async function logCompilationEvents() {
for await (const event of project.compilationEventsSubscribe()) {
if (event.severity === 'EVENT') {
Log.event(event.message)
switch (event.severity) {
case 'EVENT':
Log.event(event.message)
break
case 'TRACE':
Log.trace(event.message)
break
case 'INFO':
Log.info(event.message)
break
case 'WARNING':
Log.warn(event.message)
break
case 'ERROR':
Log.error(event.message)
break
case 'FATAL':
Log.error(event.message)
break
default:
break
}
}
})()
Expand Down
82 changes: 80 additions & 2 deletions turbopack/crates/turbo-tasks/src/message_queue.rs
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
use std::{any::Any, collections::VecDeque, fmt::Display, sync::Arc};
use std::{any::Any, collections::VecDeque, fmt::Display, sync::Arc, time::Duration};

use dashmap::DashMap;
use tokio::sync::{Mutex, mpsc};
Expand Down Expand Up @@ -141,14 +141,64 @@ impl Display for Severity {
}
}

#[derive(Debug, Clone, serde::Serialize, serde::Deserialize)]
/// Compilation event that is used to log the duration of a task
pub struct TimingEvent {
/// Message of the event without the timing information
///
/// Example:
/// ```rust
/// let event = TimingEvent::new("Compiled successfully".to_string(), Duration::from_millis(100));
/// let message = event.message();
/// assert_eq!(message, "Compiled successfully in 100ms");
/// ```
pub message: String,
/// Duration in milliseconds
pub duration: Duration,
}

impl TimingEvent {
pub fn new(message: String, duration: Duration) -> Self {
Self { message, duration }
}
}

impl CompilationEvent for TimingEvent {
fn type_name(&self) -> &'static str {
"TimingEvent"
}

fn severity(&self) -> Severity {
Severity::Event
}

fn message(&self) -> String {
let duration_secs = self.duration.as_secs_f64();
let duration_string = if duration_secs > 120.0 {
format!("{:.1}min", duration_secs / 60.0)
} else if duration_secs > 40.0 {
format!("{duration_secs:.0}s")
} else if duration_secs > 2.0 {
format!("{duration_secs:.1}s")
} else {
format!("{:.0}ms", duration_secs * 1000.0)
};
format!("{} in {}", self.message, duration_string)
}

fn to_json(&self) -> String {
serde_json::to_string(self).unwrap()
}
}

#[derive(Debug, Clone, serde::Serialize, serde::Deserialize)]
pub struct DiagnosticEvent {
pub message: String,
pub severity: Severity,
}

impl DiagnosticEvent {
pub fn new(message: String, severity: Severity) -> Self {
pub fn new(severity: Severity, message: String) -> Self {
Self { message, severity }
}
}
Expand All @@ -170,3 +220,31 @@ impl CompilationEvent for DiagnosticEvent {
serde_json::to_string(self).unwrap()
}
}

#[cfg(test)]
mod tests {
use super::*;

#[test]
fn test_timing_event_string_formatting() {
let tests = vec![
(Duration::from_nanos(1588), "0ms"),
(Duration::from_nanos(1022616), "1ms"),
(Duration::from_millis(100), "100ms"),
(Duration::from_millis(1000), "1000ms"),
(Duration::from_millis(10000), "10.0s"),
(Duration::from_millis(20381), "20.4s"),
(Duration::from_secs(60), "60s"),
(Duration::from_secs(100), "100s"),
(Duration::from_secs(125), "2.1min"),
];

for (duration, expected) in tests {
let event = TimingEvent::new("Compiled successfully".to_string(), duration);
assert_eq!(
event.message(),
format!("Compiled successfully in {expected}")
);
}
}
}
Loading