jsc: keep the code frame of a printed error for the next print of the same place

bench/sourcemap/code-frame-bench.ts

@@ -0,0 +1,100 @@
+// Microbench for the code frame of a printed error: the source lines that
+// Bun.inspect(error) and console.error(error) show above the message. Compare
+// against a baseline build by running:
+//
+//   bun run build:release bench/sourcemap/code-frame-bench.ts
+//
+// The printer cuts the frame from the whole source text. For a module that bun
+// transpiled it reads the file. For a module that has a source map (a
+// `bun build --target=bun --sourcemap` bundle) it parses the map for
+// `sourcesContent`. Both loads are O(size), so each shape runs small and large.
+
+import fs from "node:fs";
+import os from "node:os";
+import path from "node:path";
+
+const flag = process.argv[2] ?? "bench";
+// The printer keeps the frames of this many places (`CodeFrameSlots::CAPACITY`).
+const KEPT = 64;
+const LARGE_BYTES = 4 * 1024 * 1024;
+
+const dir = fs.mkdtempSync(path.join(os.tmpdir(), "code-frame-bench-"));
+process.on("exit", () => fs.rmSync(dir, { recursive: true, force: true }));
+
+type Places = { sites: (() => Error)[]; long: () => Error };
+
+// `sites[i]()` returns an error thrown on its own line. `long()` throws on a
+// line of 5000 bytes. Comment lines before and after them pad the source to
+// `bytes`, so the places are in the middle of a large source.
+function placesSource(bytes: number): string {
+  let places = "export const sites: (() => Error)[] = [\n";
+  for (let i = 0; i <= KEPT; i++) {
+    places += `  () => { try { throw new Error("site ${i}"); } catch (e) { return e as Error; } },\n`;
+  }
+  places += "];\n";
+  places += `export function long(): Error { try { throw new Error("long"); } catch (e) { return e as Error; } } // ${Buffer.alloc(5000, "p")}\n`;
+  const line = "// padding padding padding padding padding padding padding padding\n";
+  const lines = Math.max(0, bytes - places.length) / 2 / line.length;
+  const padding = Buffer.alloc(Math.floor(lines) * line.length, line).toString();
+  return padding + places + padding;
+}
+
+// Microseconds per call of `fn(i)`. A pass is `callsPerPass` calls, and only
+// whole passes are measured, for at least 250 ms.
+function measure(callsPerPass: number, fn: (i: number) => unknown): string {
+  const start = performance.now();
+  let elapsed = 0;
+  let calls = 0;
+  do {
+    for (let i = 0; i < callsPerPass; i++) fn(i);
+    calls += callsPerPass;
+    elapsed = performance.now() - start;
+  } while (elapsed < 250);
+  return ((elapsed * 1000) / calls).toFixed(2) + " µs/op";
+}
+
+function report(title: string, file: string, loadedBytes: number) {
+  const { sites, long } = require(file) as Places;
+  const print = (i: number) => Bun.inspect(sites[i]());
+
+  const start = performance.now();
+  for (let i = 0; i < KEPT; i++) print(i);
+  const first = (((performance.now() - start) * 1000) / KEPT).toFixed(2) + " µs/op";
+
+  const rows: [string, string][] = [["first print of a place", first]];
+  rows.push(["the same place again", measure(KEPT, () => print(0))]);
+  rows.push([`${KEPT} places in rotation`, measure(KEPT, print)]);
+  // With one more place than is kept, each print follows `KEPT` other places.
+  for (let i = 0; i <= KEPT; i++) print(i);
+  rows.push([`${KEPT + 1} places in rotation`, measure(KEPT + 1, print)]);
+  rows.push(["a line of 5000 bytes", measure(16, () => Bun.inspect(long()))]);
+
+  console.log(`[${flag}] ${title}, ${(loadedBytes / 1024).toFixed(0)} KB loaded per cut`);
+  for (const [name, value] of rows) console.log(`[${flag}]   ${name.padEnd(24)} ${value.padStart(16)}`);
+}
+
+// The first print of a process does work that no later print does.
+for (let i = 0; i < 5; i++) Bun.inspect(new Error("warm-up"));
+
+for (const [size, bytes] of [
+  ["small", 0],
+  ["large", LARGE_BYTES],
+] as const) {
+  const source = path.join(dir, `${size}.ts`);
+  fs.writeFileSync(source, placesSource(bytes));
+  report(`${size} module that bun transpiled`, source, fs.statSync(source).size);
+
+  // The bundle gets its own copy of the source, so that it shares no module
+  // with the run above.
+  const entry = path.join(dir, `${size}-bundled.ts`);
+  fs.copyFileSync(source, entry);
+  const build = await Bun.build({
+    entrypoints: [entry],
+    outdir: path.join(dir, "out"),
+    target: "bun",
+    sourcemap: "external",
+  });
+  if (!build.success) throw new AggregateError(build.logs, "the bundle of the fixture failed");
+  const bundle = path.join(dir, "out", `${size}-bundled.js`);
+  report(`${size} bundle with an external source map`, bundle, fs.statSync(bundle + ".map").size);
+}

src/bun_core/string/immutable.rs

@@ -1721,11 +1721,11 @@ pub fn trim_suffix<'a>(buffer: &'a [u8], suffix: &[u8]) -> &'a [u8] {
 /// The final element is the end index of the desired line
 #[derive(Copy, Clone, Default)]
 pub struct LineRange {
-    pub(crate) start: u32,
-    pub(crate) end: u32,
+    pub start: u32,
+    pub end: u32,
 }
 
-pub(crate) fn index_of_line_ranges<const LINE_RANGE_COUNT: usize>(
+pub fn index_of_line_ranges<const LINE_RANGE_COUNT: usize>(
     text: &[u8],
     target_line: u32,
 ) -> BoundedArray<LineRange, LINE_RANGE_COUNT> {

src/jsc/Counters.bind.ts

@@ -2,6 +2,10 @@ import * as b from "../codegen/bindgen-lib.ts";
 
 export default b.module({ rustPath: "crate::counters" });
 
-export const CountersObject = b.dictionary({ spawnSync_blocking: b.i32, spawn_memfd: b.i32 });
+export const CountersObject = b.dictionary({
+  spawnSync_blocking: b.i32,
+  spawn_memfd: b.i32,
+  codeFrame_sourceLoads: b.i32,
+});
 
 export const createCountersObject = b.fn({ returns: CountersObject, capability: "heap" });

src/jsc/Counters.rs

@@ -6,13 +6,16 @@ use crate::generated_bindgen::counters::CountersObject;
 pub struct Counters {
     pub(crate) spawn_sync_blocking: i32,
     pub(crate) spawn_memfd: i32,
+    /// Times the error printer asked for a whole source to cut a code frame. Each arm that it asks counts, also when it gives none.
+    pub(crate) code_frame_source_loads: i32,
 }
 
 impl Counters {
     pub fn mark(&mut self, tag: Field) {
         let slot = match tag {
             Field::SpawnSyncBlocking => &mut self.spawn_sync_blocking,
             Field::SpawnMemfd => &mut self.spawn_memfd,
+            Field::CodeFrameSourceLoads => &mut self.code_frame_source_loads,
         };
         *slot = slot.saturating_add(1);
     }
@@ -24,6 +27,7 @@ pub(crate) fn create_counters_object(heap: &JsHeap<'_>) -> CountersObject {
     CountersObject {
         spawn_sync_blocking: counters.spawn_sync_blocking,
         spawn_memfd: counters.spawn_memfd,
+        code_frame_source_loads: counters.code_frame_source_loads,
     }
 }
 
@@ -33,4 +37,6 @@ pub enum Field {
     SpawnSyncBlocking,
     #[strum(serialize = "spawn_memfd")]
     SpawnMemfd,
+    #[strum(serialize = "codeFrame_sourceLoads")]
+    CodeFrameSourceLoads,
 }

src/jsc/SavedSourceMap.rs

@@ -227,6 +227,7 @@ impl SavedSourceMap {
         }
     }
 
+    /// `rare_data::CodeFrameSlots` takes a new `ParsedSourceMap` value to mean a reload: never change in place what a stored one maps.
     pub(crate) fn put_value(&mut self, path: &[u8], value: Value) -> bun_js_printer::Result<()> {
         use bun_collections::zig_hash_map::MapEntry as Entry;
 
@@ -275,6 +276,7 @@ impl SavedSourceMap {
             // ParsedSourceMap shell (no VLQ decode, no Mapping.List) so callers
             // can hold a ref while the table mutates. The shell takes ownership
             // of the blob.
+            // Each blob gets its own shell: `CodeFrameSlots` takes a new shell to mean that the module loaded again.
             let ism = InternalSourceMap {
                 data: tagged.as_unchecked::<InternalSourceMap>() as *const u8,
             };

src/jsc/VirtualMachine.rs

@@ -6,16 +6,19 @@
 use core::cell::Cell;
 use core::ffi::{c_int, c_void};
 use core::ptr::NonNull;
+use std::sync::Arc;
 
 use bun_bundler::Transpiler;
 use bun_io as Async;
+use bun_sourcemap::ParsedSourceMap;
+use bun_sourcemap::mapping::SourceCodeOrigin;
 use bun_uws as uws;
 
 use crate::bun_string_jsc;
-use crate::counters::Counters;
+use crate::counters::{Counters, Field as Counter};
 use crate::event_loop::EventLoop;
 use crate::module_loader::{self as ModuleLoader, FetchFlags};
-use crate::rare_data::RareData;
+use crate::rare_data::{CodeFrameRanges, CodeFrameSource, RareData};
 use crate::saved_source_map::SavedSourceMap;
 use crate::{
     self as jsc, Exception, JSGlobalObject, JSInternalPromise, JSValue, JsResult, OpaqueCallback,
@@ -7021,6 +7024,18 @@ impl VirtualMachine {
         self.remap_stack_frames_mutex.unlock();
     }
 
+    /// A copy of the code frame that an earlier print kept for this place.
+    fn kept_code_frame(
+        &self,
+        (map, source): &(Arc<ParsedSourceMap>, CodeFrameSource),
+        line: i32,
+    ) -> Option<(bun_core::Utf8Bytes<'static>, CodeFrameRanges)> {
+        let slots = &self.rare_data.as_deref()?.code_frame_slots;
+        let (text, ranges) = slots.get(map, *source, line)?;
+        let ranges = CodeFrameRanges::from_slice(ranges).ok()?;
+        Some((bun_core::Utf8Bytes::Owned(text.to_vec()), ranges))
+    }
+
     /// Fills `exception` from `error_instance`, remapping stack frames through source maps.
     /// `source_code` receives the text that `exception`'s source lines borrow.
     pub(crate) fn remap_zig_exception<'a>(
@@ -7184,6 +7199,10 @@ impl VirtualMachine {
         }
 
         let already_remapped = frames[top].remapped;
+        // With the line, the place whose code frame can be kept.
+        let mut frame_key: Option<(Arc<ParsedSourceMap>, CodeFrameSource)> = None;
+        // The line ranges of the frame that an earlier print of that place kept.
+        let mut kept_ranges: Option<CodeFrameRanges> = None;
         let resolved = {
             let top_source_url = frames[top].source_url.to_utf8();
             let maybe_lookup: Option<bun_sourcemap::mapping::Lookup> = if already_remapped {
@@ -7220,22 +7239,40 @@ impl VirtualMachine {
                 } else {
                     None
                 };
-                let external_code = if enable_source_code_preview.get()
-                    && !already_remapped
-                    && lookup
-                        .source_map
-                        .as_deref()
-                        .is_some_and(|m| m.is_external())
-                {
-                    lookup.get_source_code(top_source_url.slice())
-                } else {
-                    None
+                let last_line = mapping.original.lines.zero_based().max(0);
+                // A frame that is already remapped has no map here.
+                let mut key = match &lookup.source_map {
+                    Some(map) if enable_source_code_preview.get() => {
+                        let source = if map.is_external() {
+                            CodeFrameSource::SourcesContent(mapping.source_index)
+                        } else {
+                            CodeFrameSource::ByPath
+                        };
+                        Some((Arc::clone(map), source))
+                    }
+                    _ => None,
                 };
-                (mapping, display_url, external_code)
+                let mut external_code = None;
+                if let Some(sources_content @ (_, CodeFrameSource::SourcesContent(_))) = &key {
+                    if let Some((text, ranges)) = self.kept_code_frame(sources_content, last_line) {
+                        kept_ranges = Some(ranges);
+                        external_code = Some(text);
+                    } else {
+                        self.counters.mark(Counter::CodeFrameSourceLoads);
+                        let loaded = lookup.get_source_code(top_source_url.slice());
+                        // A file read in place of the map's text is not kept under the map's source index.
+                        if !matches!(loaded, Some((_, SourceCodeOrigin::SourceMap))) {
+                            key = None;
+                        }
+                        external_code = loaded.map(|(text, _)| text);
+                    }
+                }
+                frame_key = key;
+                (mapping, display_url, external_code, last_line)
             })
         };
 
-        if let Some((mapping, display_url, external_code)) = resolved {
+        if let Some((mapping, display_url, external_code, last_line)) = resolved {
             if let Some(src) = display_url {
                 frames[top].source_url = src.into();
             }
@@ -7257,9 +7294,19 @@ impl VirtualMachine {
                     if !crate::compiled_program::runs_in_place() {
                         break 'code bun_core::Utf8Bytes::EMPTY;
                     }
+                    // Not kept. A compiled frame arrives remapped, so it has no key anyway.
+                    frame_key = None;
+                    self.counters.mark(Counter::CodeFrameSourceLoads);
                     let text = bun_sys::File::read_from(bun_sys::Fd::cwd(), top_path.slice());
                     break 'code bun_core::Utf8Bytes::Owned(text.unwrap_or_default());
                 }
+                if let Some(key @ (_, CodeFrameSource::ByPath)) = &frame_key
+                    && let Some((text, ranges)) = self.kept_code_frame(key, last_line)
+                {
+                    kept_ranges = Some(ranges);
+                    break 'code text;
+                }
+                self.counters.mark(Counter::CodeFrameSourceLoads);
                 let mut log = bun_ast::Log::default();
                 let Ok(original_source) = bun_removable_features::call_removable_or!(
                     RuntimeTranspiler,
@@ -7283,7 +7330,8 @@ impl VirtualMachine {
             *source_code = code;
             let code: &'a [u8] = source_code.slice();
 
-            if enable_source_code_preview.get() && code.is_empty() {
+            // A kept frame can be empty (an empty first line). The fallback is not for it.
+            if enable_source_code_preview.get() && code.is_empty() && kept_ranges.is_none() {
                 exception.collect_source_lines(error_instance, global);
             }
 
@@ -7293,13 +7341,18 @@ impl VirtualMachine {
             exception.remapped = true;
             frames[top].remapped = true;
 
-            let last_line = frames[top].position.line.zero_based().max(0);
-            if let Some(lines_buf) = bun_core::strings::get_lines_in_text::<
-                { crate::zig_exception::SOURCE_LINES_COUNT },
-            >(code, last_line as u32)
-            {
-                let lines = lines_buf.as_slice();
-                const N: usize = crate::zig_exception::SOURCE_LINES_COUNT;
+            const N: usize = crate::zig_exception::SOURCE_LINES_COUNT;
+            // A kept frame and a fresh one go through the same fill below.
+            let is_kept = kept_ranges.is_some();
+            let ranges = kept_ranges.unwrap_or_else(|| {
+                bun_core::strings::index_of_line_ranges::<N>(code, last_line as u32)
+            });
+            if !ranges.is_empty() {
+                if !is_kept && let Some((map, source)) = &frame_key {
+                    self.rare_data()
+                        .code_frame_slots
+                        .put(map, *source, last_line, code, &ranges);
+                }
                 // SAFETY: `Holder` backs both arrays with `[_; SOURCE_LINES_COUNT]`.
                 let source_lines =
                     unsafe { bun_core::ffi::slice_mut(exception.stack.source_lines_ptr, N) };
@@ -7311,14 +7364,15 @@ impl VirtualMachine {
                 }
                 source_line_numbers.fill(0);
 
-                let take = lines.len().min(N);
                 let mut current_line_number = last_line;
-                for (i, line) in lines[..take].iter().enumerate() {
+                // The ranges are in text order. The lines start at the error's.
+                for (i, range) in ranges.iter().rev().enumerate() {
+                    let line = &code[range.start as usize..range.end as usize];
                     source_lines[i] = bun_core::StringOrView::from_bytes(line);
                     source_line_numbers[i] = current_line_number;
                     current_line_number -= 1;
                 }
-                exception.stack.source_lines_len = take as u8;
+                exception.stack.source_lines_len = ranges.len() as u8;
             }
         } else if enable_source_code_preview.get() {
             exception.collect_source_lines(error_instance, global);