Skip to content

Commit

Permalink
HMR: Log unexpected Turbopack errors to a file (#68698)
Browse files Browse the repository at this point in the history
If a Rust Error Result is returned by an hmr update, then an unexpected internal error unrelated to the user’s code has occurred. Like #67678 does for unhandled panics, log these errors to a file and inform the user with a generic message informing them to file an issue. In development, this continues to log to stderr.
  • Loading branch information
wbinnssmith committed Sep 9, 2024
1 parent d169cf3 commit b368fea
Show file tree
Hide file tree
Showing 5 changed files with 102 additions and 93 deletions.
89 changes: 6 additions & 83 deletions crates/napi/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -35,18 +35,13 @@ extern crate napi_derive;

use std::{
env,
io::prelude::*,
panic::set_hook,
path::PathBuf,
sync::{Arc, Mutex, Once},
time::Instant,
sync::{Arc, Once},
};

use backtrace::Backtrace;
use fxhash::FxHashSet;
use napi::bindgen_prelude::*;
use once_cell::sync::Lazy;
use owo_colors::OwoColorize;
use swc_core::{
base::{Compiler, TransformOutput},
common::{FilePathMapping, SourceMap},
Expand Down Expand Up @@ -77,13 +72,6 @@ shadow_rs::shadow!(build);
#[global_allocator]
static ALLOC: turbo_tasks_malloc::TurboMalloc = turbo_tasks_malloc::TurboMalloc;

static LOG_THROTTLE: Mutex<Option<Instant>> = Mutex::new(None);
static PANIC_LOG: Lazy<PathBuf> = Lazy::new(|| {
let mut path = env::temp_dir();
path.push(format!("next-panic-{:x}.log", rand::random::<u128>()));
path
});

#[cfg(feature = "__internal_dhat-heap")]
#[global_allocator]
static ALLOC: dhat::Alloc = dhat::Alloc;
Expand All @@ -92,77 +80,12 @@ static ALLOC: dhat::Alloc = dhat::Alloc;
#[napi::module_init]

fn init() {
use std::{fs::OpenOptions, io};

set_hook(Box::new(|panic_info| {
// hold open this mutex guard to prevent concurrent writes to the file!
let mut last_error_time = LOG_THROTTLE.lock().unwrap();
if let Some(last_error_time) = last_error_time.as_ref() {
if last_error_time.elapsed().as_secs() < 1 {
// Throttle panic logging to once per second
return;
}
}
*last_error_time = Some(Instant::now());

let backtrace = Backtrace::new();
let info = format!("Panic: {}\nBacktrace: {:?}", panic_info, backtrace);
if cfg!(debug_assertions) || env::var("SWC_DEBUG") == Ok("1".to_string()) {
eprintln!("{}", info);
} else {
let size = std::fs::metadata(PANIC_LOG.as_path()).map(|m| m.len());
if let Ok(size) = size {
if size > 512 * 1024 {
// Truncate the earliest error from log file if it's larger than 512KB
let new_lines = {
let log_read = OpenOptions::new()
.read(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| {
panic!("Failed to open {}", PANIC_LOG.to_string_lossy())
});

io::BufReader::new(&log_read)
.lines()
.skip(1)
.skip_while(|line| match line {
Ok(line) => !line.starts_with("Panic:"),
Err(_) => false,
})
.collect::<Vec<_>>()
};

let mut log_write = OpenOptions::new()
.create(true)
.truncate(true)
.write(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| {
panic!("Failed to open {}", PANIC_LOG.to_string_lossy())
});

for line in new_lines {
match line {
Ok(line) => {
writeln!(log_write, "{}", line).unwrap();
}
Err(_) => {
break;
}
}
}
}
}

let mut log_file = OpenOptions::new()
.create(true)
.append(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| panic!("Failed to open {}", PANIC_LOG.to_string_lossy()));

writeln!(log_file, "{}", info).unwrap();
eprintln!("{}: An unexpected Turbopack error occurred. Please report the content of {} to https://github.com/vercel/next.js/issues/new", "FATAL".red().bold(), PANIC_LOG.to_string_lossy());
}
util::log_panic_and_inform(format!(
"Panic: {}\nBacktrace: {:?}",
panic_info,
Backtrace::new()
));
}));
}

Expand Down
5 changes: 3 additions & 2 deletions crates/napi/src/next_api/project.rs
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,7 @@ use super::{
TurbopackResult, VcArc,
},
};
use crate::register;
use crate::{register, util::log_panic_and_inform};

/// Used by [`benchmark_file_io`]. This is a noisy benchmark, so set the
/// threshold high.
Expand Down Expand Up @@ -735,7 +735,8 @@ pub fn project_hmr_events(
let state = project.hmr_version_state(identifier.clone(), session);
let update = hmr_update(project, identifier, state)
.strongly_consistent()
.await?;
.await
.inspect_err(|e| log_panic_and_inform(e))?;
let HmrUpdateWithIssues {
update,
issues,
Expand Down
87 changes: 86 additions & 1 deletion crates/napi/src/util.rs
Original file line number Diff line number Diff line change
Expand Up @@ -26,13 +26,98 @@ IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
DEALINGS IN THE SOFTWARE.
*/

use std::{cell::RefCell, path::PathBuf};
use std::{
cell::RefCell,
env,
fmt::Debug,
fs::OpenOptions,
io::{self, BufRead, Write},
path::PathBuf,
sync::Mutex,
time::Instant,
};

use anyhow::anyhow;
use napi::bindgen_prelude::{External, Status};
use once_cell::sync::Lazy;
use owo_colors::OwoColorize;
use tracing_chrome::{ChromeLayerBuilder, FlushGuard};
use tracing_subscriber::{filter, prelude::*, util::SubscriberInitExt, Layer};

static LOG_THROTTLE: Mutex<Option<Instant>> = Mutex::new(None);
static LOG_DIVIDER: &str = "---------------------------";
static PANIC_LOG: Lazy<PathBuf> = Lazy::new(|| {
let mut path = env::temp_dir();
path.push(format!("next-panic-{:x}.log", rand::random::<u128>()));
path
});

pub fn log_panic_and_inform(err_info: impl Debug) {
if cfg!(debug_assertions) || env::var("SWC_DEBUG") == Ok("1".to_string()) {
eprintln!("{:?}", err_info);
return;
}

// hold open this mutex guard to prevent concurrent writes to the file!
let mut last_error_time = LOG_THROTTLE.lock().unwrap();
if let Some(last_error_time) = last_error_time.as_ref() {
if last_error_time.elapsed().as_secs() < 1 {
// Throttle panic logging to once per second
return;
}
}
*last_error_time = Some(Instant::now());

let size = std::fs::metadata(PANIC_LOG.as_path()).map(|m| m.len());
if let Ok(size) = size {
if size > 512 * 1024 {
// Truncate the earliest error from log file if it's larger than 512KB
let new_lines = {
let log_read = OpenOptions::new()
.read(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| panic!("Failed to open {}", PANIC_LOG.to_string_lossy()));

io::BufReader::new(&log_read)
.lines()
.skip(1)
.skip_while(|line| match line {
Ok(line) => !line.starts_with(LOG_DIVIDER),
Err(_) => false,
})
.collect::<Vec<_>>()
};

let mut log_write = OpenOptions::new()
.create(true)
.truncate(true)
.write(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| panic!("Failed to open {}", PANIC_LOG.to_string_lossy()));

for line in new_lines {
match line {
Ok(line) => {
writeln!(log_write, "{}", line).unwrap();
}
Err(_) => {
break;
}
}
}
}
}

let mut log_file = OpenOptions::new()
.create(true)
.append(true)
.open(PANIC_LOG.as_path())
.unwrap_or_else(|_| panic!("Failed to open {}", PANIC_LOG.to_string_lossy()));

writeln!(log_file, "{}\n{:?}", LOG_DIVIDER, err_info).unwrap();
eprintln!("{}: An unexpected Turbopack error occurred. Please report the content of {} to https://github.com/vercel/next.js/issues/new", "FATAL".red().bold(), PANIC_LOG.to_string_lossy());
}

#[napi]
pub fn get_target_triple() -> String {
crate::build::BUILD_TARGET.to_string()
Expand Down
7 changes: 4 additions & 3 deletions packages/next/src/build/swc/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -818,9 +818,7 @@ function bindingToApi(
try {
return await fn()
} catch (nativeError: any) {
throw new TurbopackInternalError(nativeError.message, {
cause: nativeError,
})
throw new TurbopackInternalError(nativeError)
}
}

Expand Down Expand Up @@ -883,6 +881,9 @@ function bindingToApi(
}
} catch (e) {
if (e === cancel) return
if (e instanceof Error) {
throw new TurbopackInternalError(e)
}
throw e
} finally {
binding.rootTaskDispose(task)
Expand Down
7 changes: 3 additions & 4 deletions packages/next/src/server/dev/turbopack-utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -54,11 +54,10 @@ export class ModuleBuildError extends Error {
// to a log file and details should not be shown to the user.
export class TurbopackInternalError extends Error {
name = 'TurbopackInternalError'
cause: unknown

constructor(message: string, cause: unknown) {
super(message)
this.cause = cause
constructor(cause: Error) {
super(cause.message)
this.stack = cause.stack
}
}

Expand Down

0 comments on commit b368fea

Please sign in to comment.