Skip to content
Open
Show file tree
Hide file tree
Changes from 1 commit
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
31 changes: 30 additions & 1 deletion src/install/PackageManager/PackageManagerLifecycle.rs
Original file line number Diff line number Diff line change
Expand Up @@ -34,14 +34,43 @@
list: Vec<LifecycleScriptTimeLogEntry>,
}

pub struct LifecycleScriptTimeLogEntry {}
pub struct LifecycleScriptTimeLogEntry {
pub(crate) package_name: Box<[u8]>,
pub(crate) script_id: u8,
/// nanoseconds
pub(crate) duration: u64,
}

impl LifecycleScriptTimeLog {
pub(crate) fn append_concurrent(&mut self, entry: LifecycleScriptTimeLogEntry) {
self.mutex.lock();
self.list.push(entry);
self.mutex.unlock();
}

/// Print the single slowest entry as a warning. Safe to call when no
/// entries were recorded.
Comment thread
robobun marked this conversation as resolved.
Outdated
pub(crate) fn print(&mut self) {
if bun_core::env::IS_DEBUG {
debug_assert!(
self.mutex.try_lock(),
"LifecycleScriptTimeLog.print is not intended to be thread-safe"
);
self.mutex.unlock();
}

Check failure on line 60 in src/install/PackageManager/PackageManagerLifecycle.rs

View check run for this annotation

Claude / Claude Code Review

Release build failure: Mutex::try_lock is #[cfg(debug_assertions)]-gated

This breaks release builds: `bun_threading::Mutex::try_lock` is `#[cfg(debug_assertions)]`-gated (src/threading/Mutex.rs:53), so the method does not exist when `debug_assertions` is off, and `if IS_DEBUG { debug_assert!(...) }` is a runtime const-if whose body is still type-checked. Wrap the block in `#[cfg(debug_assertions)] { ... }` instead (as every other `bun_threading::Mutex::try_lock` call site in-tree does); `bun run rust:check-all` didn't catch this because it only runs `cargo check` in
Comment thread
robobun marked this conversation as resolved.
Outdated

if let Some(longest) = self.list.iter().max_by_key(|e| e.duration) {
// extra \n prints a blank line after this one
bun_core::warn!(
"{}'s {} script took {}\n",
BStr::new(&longest.package_name),
lockfile::Scripts::NAMES[longest.script_id as usize],
bun_fmt::fmt_duration_one_decimal(longest.duration),
);
Comment thread
robobun marked this conversation as resolved.
Outdated
Output::flush();
}
self.list.clear();
}
}

impl PackageManager {
Expand Down
2 changes: 2 additions & 0 deletions src/install/PackageManager/install_with_manager.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1034,6 +1034,8 @@ fn print_install_summary(
if this.options.do_.summary() {
print_summary_tree(this, install_summary, log_level)?;

this.lifecycle_script_time_log.print();

if !did_meta_hash_change {
this.summary.remove = 0;
this.summary.add = 0;
Expand Down
7 changes: 6 additions & 1 deletion src/install/lifecycle_script_runner.rs
Original file line number Diff line number Diff line change
Expand Up @@ -676,6 +676,7 @@ impl<'a> LifecycleScriptSubprocess<'a> {
(*this).remaining_fds = 0;
(*this).started_at =
bun_core::Timespec::now(bun_core::TimespecMockMode::AllowMockedTime).ns();
(*this).timer = Some(Timer::start());
// Store the allocation-rooted `this` in the intrusive heap — not a `&mut self`
// reborrow, whose SB tag would be invalidated by the field accesses below.
(*manager)
Expand Down Expand Up @@ -911,7 +912,11 @@ impl<'a> LifecycleScriptSubprocess<'a> {

if let Some(nanos) = maybe_duration {
if nanos > MIN_MILLISECONDS_TO_LOG * bun_core::time::NS_PER_MS {
let entry = LifecycleScriptTimeLogEntry {};
let entry = LifecycleScriptTimeLogEntry {
package_name: self.package_name.clone(),
script_id: self.current_script_index,
duration: nanos,
};
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Outdated
// SAFETY: see [`Self::manager_mut`].
unsafe { self.manager_mut() }
.lifecycle_script_time_log
Expand Down
44 changes: 44 additions & 0 deletions test/cli/install/bun-install-lifecycle-scripts.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2135,6 +2135,50 @@ for (const forceWaiterThread of isLinux ? [false, true] : [false]) {
return dependenciesList;
}

test("slow lifecycle script prints a warning", async () => {
using ctx = await setupTest();
const { packageDir, packageJson, env } = ctx;
const testEnv = forceWaiterThread ? { ...env, BUN_FEATURE_FLAG_FORCE_WAITER_THREAD: "1" } : env;

await mkdir(join(packageDir, "slow-pkg"));
await writeFile(
join(packageDir, "slow-pkg", "package.json"),
JSON.stringify({
name: "slow-pkg",
version: "1.0.0",
scripts: {
postinstall: `${bunExe()} -e 'Bun.sleepSync(750)'`,
},
}),
);
await writeFile(
packageJson,
JSON.stringify({
name: "foo",
version: "1.0.0",
dependencies: {
"slow-pkg": "file:./slow-pkg",
},
trustedDependencies: ["slow-pkg"],
}),
);

const { stdout, stderr, exited } = spawn({
cmd: [bunExe(), "install"],
cwd: packageDir,
stdout: "pipe",
stdin: "ignore",
stderr: "pipe",
env: testEnv,
});

const [err, out, exitCode] = await Promise.all([stderr.text(), stdout.text(), exited]);
expect(err).not.toContain("error:");
expect(err).toMatch(/warn: slow-pkg's postinstall script took \d/);
expect(out).toContain("1 package installed");
expect(exitCode).toBe(0);
Comment thread
coderabbitai[bot] marked this conversation as resolved.
});

test("reach max concurrent scripts", async () => {
using ctx = await setupTest();
const { packageDir, packageJson, env } = ctx;
Expand Down
5 changes: 3 additions & 2 deletions test/harness.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1511,9 +1511,10 @@ export async function runBunInstall(
return { out, err, exited };
}

// stderr with `slow filesystem` warning removed
// stderr with timing-dependent warnings removed (debug/ASAN builds can push any
// lifecycle script over the 500ms slow-script threshold)
export function stderrForInstall(err: string) {
return err.replace(/warn: Slow filesystem.*/g, "");
return err.replace(/warn: Slow filesystem.*/g, "").replace(/warn: .*'s \S+ script took .*\n?\n?/g, "");
}

export async function runBunUpdate(
Expand Down
Loading