Update the messaging UX on messaging for timing writing files to disk

Additional Changes:

* Changed severity of "Starting the compilation events sever" to `info` to match other messaging like it
* Began printing all compilation events now that it has been proven to work correctly
* Added a `TimingEvent` for these types of messages
    - Made the messaging follow the rules for timing information from how Next.js formats timing info

Author: Cy-Tek

crates/napi/src/next_api/project.rs

@@ -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,
@@ -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");
@@ -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()))

packages/next/src/build/turbopack-build/impl.ts

@@ -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':
+            console.warn(event.message)
+            break
+          case 'ERROR':
+            Log.error(event.message)
+            break
+          case 'FATAL':
+            Log.error(event.message)
+            break
+          default:
+            break
         }
       }
     })()

turbopack/crates/turbo-tasks/src/message_queue.rs

@@ -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};
@@ -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!("{:.0}s", duration_secs)
+        } else if duration_secs > 2.0 {
+            format!("{:.1}s", duration_secs)
+        } 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 }
     }
 }