diff --git a/src/bun.js.zig b/src/bun.js.zig index 9c6d389202..96936ec775 100644 --- a/src/bun.js.zig +++ b/src/bun.js.zig @@ -283,6 +283,8 @@ pub const Run = struct { vm.cpu_profiler_config = CPUProfiler.CPUProfilerConfig{ .name = cpu_prof_opts.name orelse bun.env_var.BUN_CPU_PROFILE_NAME.get() orelse "", .dir = cpu_prof_opts.dir orelse bun.env_var.BUN_CPU_PROFILE_DIR.get() orelse "", + .md_format = cpu_prof_opts.md_format, + .json_format = cpu_prof_opts.json_format, }; CPUProfiler.startCPUProfiler(vm.jsc_vm); bun.analytics.Features.cpu_profile += 1; diff --git a/src/bun.js/bindings/BunCPUProfiler.cpp b/src/bun.js/bindings/BunCPUProfiler.cpp index 4038cb5ee4..c879ced1f3 100644 --- a/src/bun.js/bindings/BunCPUProfiler.cpp +++ b/src/bun.js/bindings/BunCPUProfiler.cpp @@ -7,6 +7,7 @@ #include #include #include +#include #include #include #include @@ -17,7 +18,7 @@ #include extern "C" void Bun__startCPUProfiler(JSC::VM* vm); -extern "C" BunString Bun__stopCPUProfilerAndGetJSON(JSC::VM* vm); +extern "C" void Bun__stopCPUProfiler(JSC::VM* vm, BunString* outJSON, BunString* outText); namespace Bun { @@ -334,6 +335,759 @@ WTF::String stopCPUProfilerAndGetJSON(JSC::VM& vm) return json->toJSONString(); } +// ============================================================================ +// TEXT FORMAT OUTPUT (grep-friendly, designed for LLM analysis) +// ============================================================================ + +// Structure to hold aggregated function statistics for text output +struct FunctionStats { + WTF::String functionName; + WTF::String location; // file:line format + long long selfTimeUs = 0; // microseconds where this function was at top of stack + long long totalTimeUs = 0; // microseconds including children + int selfSamples = 0; // samples where this function was at top + int totalSamples = 0; // samples where this function appeared anywhere + WTF::HashMap callers; // caller location -> count + WTF::HashMap callees; // callee location -> count +}; + +// Helper to format a function name properly +// - Empty names become "(anonymous)" +// - Async functions get "async " prefix +static WTF::String formatFunctionName(const WTF::String& name, const JSC::SamplingProfiler::StackFrame& frame) +{ + WTF::String displayName = name.isEmpty() ? "(anonymous)"_s : name; + + // Check if this is an async function and add prefix if needed + if (frame.frameType == JSC::SamplingProfiler::FrameType::Executable && frame.executable) { + if (auto* functionExecutable = jsDynamicCast(frame.executable)) { + if (JSC::isAsyncFunctionParseMode(functionExecutable->parseMode())) { + if (!displayName.startsWith("async "_s)) { + return makeString("async "_s, displayName); + } + } + } + } + + return displayName; +} + +// Helper to format a location string from URL and line number +static WTF::String formatLocation(const WTF::String& url, int lineNumber) +{ + if (url.isEmpty()) + return "[native code]"_s; + + // Extract path from file:// URL using WTF::URL + WTF::String path = url; + WTF::URL parsedUrl { url }; + if (parsedUrl.isValid() && parsedUrl.protocolIsFile()) + path = parsedUrl.fileSystemPath(); + + if (lineNumber >= 0) { + WTF::StringBuilder sb; + sb.append(path); + sb.append(':'); + sb.append(lineNumber); + return sb.toString(); + } + return path; +} + +// Helper to format time in human-readable form +static WTF::String formatTime(double microseconds) +{ + WTF::StringBuilder sb; + if (microseconds >= 1000000.0) { + // Format as seconds with 2 decimal places + double seconds = microseconds / 1000000.0; + sb.append(static_cast(seconds)); + sb.append('.'); + int frac = static_cast((seconds - static_cast(seconds)) * 100); + if (frac < 10) sb.append('0'); + sb.append(frac); + sb.append('s'); + return sb.toString(); + } + if (microseconds >= 1000.0) { + // Format as milliseconds with 1 decimal place + double ms = microseconds / 1000.0; + sb.append(static_cast(ms)); + sb.append('.'); + int frac = static_cast((ms - static_cast(ms)) * 10); + sb.append(frac); + sb.append("ms"_s); + return sb.toString(); + } + sb.append(static_cast(microseconds)); + sb.append("us"_s); + return sb.toString(); +} + +// Helper to format percentage +static WTF::String formatPercent(double value, double total) +{ + if (total <= 0) + return "0.0%"_s; + double pct = (value / total) * 100.0; + // Cap at 100% for display purposes (can exceed 100% due to rounding or overlapping time accounting) + if (pct > 100.0) + pct = 100.0; + WTF::StringBuilder sb; + // Format as XX.X% with 1 decimal place + sb.append(static_cast(pct)); + sb.append('.'); + int frac = static_cast((pct - static_cast(pct)) * 10); + sb.append(frac); + sb.append('%'); + return sb.toString(); +} + +// Key separator for building composite keys (function name + location) +// Using ASCII control character SOH (0x01) which won't appear in function names or URLs +static constexpr auto kKeySeparator = "\x01"_s; + +// Helper to escape pipe characters for markdown table cells (non-code cells) +static WTF::String escapeMarkdownTableCell(const WTF::String& str) +{ + bool needsEscape = false; + for (unsigned i = 0; i < str.length(); i++) { + if (str[i] == '|') { + needsEscape = true; + break; + } + } + if (!needsEscape) + return str; + + WTF::StringBuilder sb; + for (unsigned i = 0; i < str.length(); i++) { + UChar c = str[i]; + if (c == '|') + sb.append("\\|"_s); + else + sb.append(c); + } + return sb.toString(); +} + +// Helper to format a string as an inline code span that handles backticks properly +// Uses the CommonMark spec: use N+1 backticks as delimiter where N is the longest run of backticks in the string +static WTF::String formatCodeSpan(const WTF::String& str) +{ + // Also escape pipes since this will be used in table cells + WTF::String escaped = escapeMarkdownTableCell(str); + + // Find the longest run of backticks in the string + int maxBackticks = 0; + int currentRun = 0; + for (unsigned i = 0; i < escaped.length(); i++) { + if (escaped[i] == '`') { + currentRun++; + if (currentRun > maxBackticks) + maxBackticks = currentRun; + } else { + currentRun = 0; + } + } + + // If no backticks, use simple single backtick delimiters + if (maxBackticks == 0) { + WTF::StringBuilder sb; + sb.append('`'); + sb.append(escaped); + sb.append('`'); + return sb.toString(); + } + + // Use N+1 backticks as delimiter + int delimiterLength = maxBackticks + 1; + WTF::StringBuilder sb; + for (int i = 0; i < delimiterLength; i++) + sb.append('`'); + + // Add space padding if content starts or ends with backtick (CommonMark requirement) + bool startsWithBacktick = !escaped.isEmpty() && escaped[0] == '`'; + bool endsWithBacktick = !escaped.isEmpty() && escaped[escaped.length() - 1] == '`'; + + if (startsWithBacktick || endsWithBacktick) + sb.append(' '); + sb.append(escaped); + if (startsWithBacktick || endsWithBacktick) + sb.append(' '); + + for (int i = 0; i < delimiterLength; i++) + sb.append('`'); + + return sb.toString(); +} + +// Helper to generate a minimal valid cpuprofile JSON with no samples +static WTF::String generateEmptyProfileJSON() +{ + // Return a minimal valid Chrome DevTools CPU profile format + // Use s_profilingStartTime if available, otherwise fall back to current time + long long timestamp; + if (s_profilingStartTime > 0) + timestamp = static_cast(s_profilingStartTime); + else + timestamp = static_cast(WTF::WallTime::now().secondsSinceEpoch().value() * 1000000.0); + + WTF::StringBuilder sb; + sb.append("{\"nodes\":[{\"id\":1,\"callFrame\":{\"functionName\":\"(root)\",\"scriptId\":\"0\",\"url\":\"\",\"lineNumber\":-1,\"columnNumber\":-1},\"hitCount\":0,\"children\":[]}],\"startTime\":"_s); + sb.append(timestamp); + sb.append(",\"endTime\":"_s); + sb.append(timestamp); + sb.append(",\"samples\":[],\"timeDeltas\":[]}"_s); + return sb.toString(); +} + +// Unified function that stops the profiler and generates requested output formats +void stopCPUProfiler(JSC::VM& vm, WTF::String* outJSON, WTF::String* outText) +{ + s_isProfilerRunning = false; + + JSC::SamplingProfiler* profiler = vm.samplingProfiler(); + if (!profiler) { + if (outJSON) *outJSON = WTF::String(); + if (outText) *outText = WTF::String(); + return; + } + + // JSLock is re-entrant, so always acquiring it handles both JS and shutdown contexts + JSC::JSLockHolder locker(vm); + + // Defer GC while we're working with stack traces + JSC::DeferGC deferGC(vm); + + // Pause the profiler while holding the lock + auto& lock = profiler->getLock(); + WTF::Locker profilerLocker { lock }; + profiler->pause(); + + // releaseStackTraces() calls processUnverifiedStackTraces() internally + auto stackTraces = profiler->releaseStackTraces(); + profiler->clearData(); + + // If neither output is requested, we're done + if (!outJSON && !outText) + return; + + if (stackTraces.isEmpty()) { + if (outJSON) *outJSON = generateEmptyProfileJSON(); + if (outText) *outText = "No samples collected.\n"_s; + return; + } + + // Sort traces by timestamp once for both formats + WTF::Vector sortedIndices; + sortedIndices.reserveInitialCapacity(stackTraces.size()); + for (size_t i = 0; i < stackTraces.size(); i++) { + sortedIndices.append(i); + } + std::sort(sortedIndices.begin(), sortedIndices.end(), [&stackTraces](size_t a, size_t b) { + return stackTraces[a].timestamp < stackTraces[b].timestamp; + }); + + // Generate JSON format if requested + if (outJSON) { + // Map from stack frame signature to node ID + WTF::HashMap nodeMap; + WTF::Vector nodes; + + // Create root node + ProfileNode rootNode; + rootNode.id = 1; + rootNode.functionName = "(root)"_s; + rootNode.url = ""_s; + rootNode.scriptId = 0; + rootNode.lineNumber = -1; + rootNode.columnNumber = -1; + rootNode.hitCount = 0; + nodes.append(WTF::move(rootNode)); + + int nextNodeId = 2; + WTF::Vector samples; + WTF::Vector timeDeltas; + + double startTime = s_profilingStartTime; + double lastTime = s_profilingStartTime; + + for (size_t idx : sortedIndices) { + auto& stackTrace = stackTraces[idx]; + if (stackTrace.frames.isEmpty()) { + samples.append(1); + double currentTime = stackTrace.timestamp.approximateWallTime().secondsSinceEpoch().value() * 1000000.0; + double delta = std::max(0.0, currentTime - lastTime); + timeDeltas.append(static_cast(delta)); + lastTime = currentTime; + continue; + } + + int currentParentId = 1; + + for (int i = stackTrace.frames.size() - 1; i >= 0; i--) { + auto& frame = stackTrace.frames[i]; + + WTF::String functionName = frame.displayName(vm); + WTF::String url; + int scriptId = 0; + int lineNumber = -1; + int columnNumber = -1; + + if (frame.frameType == JSC::SamplingProfiler::FrameType::Executable && frame.executable) { + auto sourceProviderAndID = frame.sourceProviderAndID(); + auto* provider = std::get<0>(sourceProviderAndID); + if (provider) { + url = provider->sourceURL(); + scriptId = static_cast(provider->asID()); + + bool isAbsolutePath = false; + if (!url.isEmpty()) { + if (url[0] == '/') + isAbsolutePath = true; + else if (url.length() >= 2 && url[1] == ':') { + char firstChar = url[0]; + if ((firstChar >= 'A' && firstChar <= 'Z') || (firstChar >= 'a' && firstChar <= 'z')) + isAbsolutePath = true; + } else if (url.length() >= 2 && url[0] == '\\' && url[1] == '\\') + isAbsolutePath = true; + } + + if (isAbsolutePath) + url = WTF::URL::fileURLWithFileSystemPath(url).string(); + } + + if (frame.hasExpressionInfo()) { + JSC::LineColumn sourceMappedLineColumn = frame.semanticLocation.lineColumn; + if (provider) { +#if USE(BUN_JSC_ADDITIONS) + auto& fn = vm.computeLineColumnWithSourcemap(); + if (fn) + fn(vm, provider, sourceMappedLineColumn); +#endif + } + lineNumber = static_cast(sourceMappedLineColumn.line); + columnNumber = static_cast(sourceMappedLineColumn.column); + } + } + + WTF::StringBuilder keyBuilder; + keyBuilder.append(currentParentId); + keyBuilder.append(':'); + keyBuilder.append(functionName); + keyBuilder.append(':'); + keyBuilder.append(url); + keyBuilder.append(':'); + keyBuilder.append(scriptId); + keyBuilder.append(':'); + keyBuilder.append(lineNumber); + keyBuilder.append(':'); + keyBuilder.append(columnNumber); + + WTF::String key = keyBuilder.toString(); + + int nodeId; + auto it = nodeMap.find(key); + if (it == nodeMap.end()) { + nodeId = nextNodeId++; + nodeMap.add(key, nodeId); + + ProfileNode node; + node.id = nodeId; + node.functionName = functionName; + node.url = url; + node.scriptId = scriptId; + node.lineNumber = lineNumber; + node.columnNumber = columnNumber; + node.hitCount = 0; + + nodes.append(WTF::move(node)); + + if (currentParentId > 0) + nodes[currentParentId - 1].children.append(nodeId); + } else { + nodeId = it->value; + } + + currentParentId = nodeId; + + if (i == 0) + nodes[nodeId - 1].hitCount++; + } + + samples.append(currentParentId); + + double currentTime = stackTrace.timestamp.approximateWallTime().secondsSinceEpoch().value() * 1000000.0; + double delta = std::max(0.0, currentTime - lastTime); + timeDeltas.append(static_cast(delta)); + lastTime = currentTime; + } + + double endTime = lastTime; + + // Build JSON + using namespace WTF; + auto json = JSON::Object::create(); + + auto nodesArray = JSON::Array::create(); + for (const auto& node : nodes) { + auto nodeObj = JSON::Object::create(); + nodeObj->setInteger("id"_s, node.id); + + auto callFrame = JSON::Object::create(); + callFrame->setString("functionName"_s, node.functionName); + callFrame->setString("scriptId"_s, WTF::String::number(node.scriptId)); + callFrame->setString("url"_s, node.url); + callFrame->setInteger("lineNumber"_s, node.lineNumber); + callFrame->setInteger("columnNumber"_s, node.columnNumber); + + nodeObj->setValue("callFrame"_s, callFrame); + nodeObj->setInteger("hitCount"_s, node.hitCount); + + if (!node.children.isEmpty()) { + auto childrenArray = JSON::Array::create(); + WTF::HashSet seenChildren; + for (int childId : node.children) { + if (seenChildren.add(childId).isNewEntry) + childrenArray->pushInteger(childId); + } + nodeObj->setValue("children"_s, childrenArray); + } + + nodesArray->pushValue(nodeObj); + } + json->setValue("nodes"_s, nodesArray); + + json->setDouble("startTime"_s, startTime); + json->setDouble("endTime"_s, endTime); + + auto samplesArray = JSON::Array::create(); + for (int sample : samples) + samplesArray->pushInteger(sample); + json->setValue("samples"_s, samplesArray); + + auto timeDeltasArray = JSON::Array::create(); + for (long long delta : timeDeltas) + timeDeltasArray->pushInteger(delta); + json->setValue("timeDeltas"_s, timeDeltasArray); + + *outJSON = json->toJSONString(); + } + + // Generate text format if requested + if (outText) { + double startTime = s_profilingStartTime; + double lastTime = s_profilingStartTime; + double endTime = startTime; + + WTF::HashMap functionStatsMap; + + long long totalTimeUs = 0; + int totalSamples = static_cast(stackTraces.size()); + + for (size_t idx : sortedIndices) { + auto& stackTrace = stackTraces[idx]; + + double currentTime = stackTrace.timestamp.approximateWallTime().secondsSinceEpoch().value() * 1000000.0; + long long deltaUs = static_cast(std::max(0.0, currentTime - lastTime)); + totalTimeUs += deltaUs; + lastTime = currentTime; + endTime = currentTime; + + if (stackTrace.frames.isEmpty()) + continue; + + WTF::String previousKey; + + for (int i = stackTrace.frames.size() - 1; i >= 0; i--) { + auto& frame = stackTrace.frames[i]; + + WTF::String rawFunctionName = frame.displayName(vm); + WTF::String functionName = formatFunctionName(rawFunctionName, frame); + WTF::String url; + int lineNumber = -1; + + if (frame.frameType == JSC::SamplingProfiler::FrameType::Executable && frame.executable) { + auto sourceProviderAndID = frame.sourceProviderAndID(); + auto* provider = std::get<0>(sourceProviderAndID); + if (provider) { + url = provider->sourceURL(); + + bool isAbsolutePath = false; + if (!url.isEmpty()) { + if (url[0] == '/') + isAbsolutePath = true; + else if (url.length() >= 2 && url[1] == ':') { + char firstChar = url[0]; + if ((firstChar >= 'A' && firstChar <= 'Z') || (firstChar >= 'a' && firstChar <= 'z')) + isAbsolutePath = true; + } else if (url.length() >= 2 && url[0] == '\\' && url[1] == '\\') + isAbsolutePath = true; + } + if (isAbsolutePath) + url = WTF::URL::fileURLWithFileSystemPath(url).string(); + } + + if (frame.hasExpressionInfo()) { + JSC::LineColumn sourceMappedLineColumn = frame.semanticLocation.lineColumn; + if (provider) { +#if USE(BUN_JSC_ADDITIONS) + auto& fn = vm.computeLineColumnWithSourcemap(); + if (fn) + fn(vm, provider, sourceMappedLineColumn); +#endif + } + lineNumber = static_cast(sourceMappedLineColumn.line); + } + } + + WTF::String location = formatLocation(url, lineNumber); + // Key uses zero-width space separator internally (not shown in output) + WTF::StringBuilder keyBuilder; + keyBuilder.append(functionName); + keyBuilder.append(kKeySeparator); + keyBuilder.append(location); + WTF::String key = keyBuilder.toString(); + + auto result = functionStatsMap.add(key, FunctionStats()); + FunctionStats& stats = result.iterator->value; + if (result.isNewEntry) { + stats.functionName = functionName; + stats.location = location; + } + + stats.totalSamples++; + stats.totalTimeUs += deltaUs; + + if (i == 0) { + stats.selfSamples++; + stats.selfTimeUs += deltaUs; + } + + if (!previousKey.isEmpty()) { + stats.callers.add(previousKey, 0).iterator->value++; + + auto prevIt = functionStatsMap.find(previousKey); + if (prevIt != functionStatsMap.end()) + prevIt->value.callees.add(key, 0).iterator->value++; + } + + previousKey = key; + } + } + + // Sort functions by self time + WTF::Vector> sortedBySelf; + for (auto& entry : functionStatsMap) + sortedBySelf.append({ entry.key, &entry.value }); + std::sort(sortedBySelf.begin(), sortedBySelf.end(), [](const auto& a, const auto& b) { + return a.second->selfTimeUs > b.second->selfTimeUs; + }); + + // Sort functions by total time + WTF::Vector> sortedByTotal; + for (auto& entry : functionStatsMap) + sortedByTotal.append({ entry.key, &entry.value }); + std::sort(sortedByTotal.begin(), sortedByTotal.end(), [](const auto& a, const auto& b) { + return a.second->totalTimeUs > b.second->totalTimeUs; + }); + + // Build the text output (Markdown format optimized for GitHub rendering + LLM analysis) + WTF::StringBuilder output; + int numFunctions = static_cast(functionStatsMap.size()); + + // Header with key metrics + output.append("# CPU Profile\n\n"_s); + output.append("| Duration | Samples | Interval | Functions |\n"_s); + output.append("|----------|---------|----------|----------|\n"_s); + output.append("| "_s); + output.append(formatTime(endTime - startTime)); + output.append(" | "_s); + output.append(totalSamples); + output.append(" | "_s); + output.append(formatTime(s_samplingInterval)); + output.append(" | "_s); + output.append(numFunctions); + output.append(" |\n\n"_s); + + // Top 10 summary for quick orientation + output.append("**Top 10:** "_s); + int topCount = 0; + for (auto& [key, stats] : sortedBySelf) { + if (stats->selfTimeUs == 0 || topCount >= 10) + break; + if (topCount > 0) output.append(", "_s); + output.append(formatCodeSpan(stats->functionName)); + output.append(' '); + output.append(formatPercent(stats->selfTimeUs, totalTimeUs)); + topCount++; + } + output.append("\n\n"_s); + + // Hot functions by self time (where time is actually spent) + output.append("## Hot Functions (Self Time)\n\n"_s); + output.append("| Self% | Self | Total% | Total | Function | Location |\n"_s); + output.append("|------:|-----:|-------:|------:|----------|----------|\n"_s); + + for (auto& [key, stats] : sortedBySelf) { + // Skip functions with 0 self time + if (stats->selfTimeUs == 0) + continue; + output.append("| "_s); + output.append(formatPercent(stats->selfTimeUs, totalTimeUs)); + output.append(" | "_s); + output.append(formatTime(stats->selfTimeUs)); + output.append(" | "_s); + output.append(formatPercent(stats->totalTimeUs, totalTimeUs)); + output.append(" | "_s); + output.append(formatTime(stats->totalTimeUs)); + output.append(" | "_s); + output.append(formatCodeSpan(stats->functionName)); + output.append(" | "_s); + output.append(formatCodeSpan(stats->location)); + output.append(" |\n"_s); + } + output.append('\n'); + + // Call tree (total time) - shows the call hierarchy + output.append("## Call Tree (Total Time)\n\n"_s); + output.append("| Total% | Total | Self% | Self | Function | Location |\n"_s); + output.append("|-------:|------:|------:|-----:|----------|----------|\n"_s); + + for (auto& [key, stats] : sortedByTotal) { + output.append("| "_s); + output.append(formatPercent(stats->totalTimeUs, totalTimeUs)); + output.append(" | "_s); + output.append(formatTime(stats->totalTimeUs)); + output.append(" | "_s); + output.append(formatPercent(stats->selfTimeUs, totalTimeUs)); + output.append(" | "_s); + output.append(formatTime(stats->selfTimeUs)); + output.append(" | "_s); + output.append(formatCodeSpan(stats->functionName)); + output.append(" | "_s); + output.append(formatCodeSpan(stats->location)); + output.append(" |\n"_s); + } + output.append('\n'); + + // Function details with call relationships + output.append("## Function Details\n\n"_s); + + for (auto& [key, stats] : sortedBySelf) { + // Skip functions with no self time and no interesting relationships + if (stats->selfTimeUs == 0 && stats->callers.isEmpty() && stats->callees.isEmpty()) + continue; + + // Header: ### `functionName` + output.append("### "_s); + output.append(formatCodeSpan(stats->functionName)); + output.append("\n"_s); + + // Location and stats on one line for density + output.append(formatCodeSpan(stats->location)); + output.append(" | Self: "_s); + output.append(formatPercent(stats->selfTimeUs, totalTimeUs)); + output.append(" ("_s); + output.append(formatTime(stats->selfTimeUs)); + output.append(") | Total: "_s); + output.append(formatPercent(stats->totalTimeUs, totalTimeUs)); + output.append(" ("_s); + output.append(formatTime(stats->totalTimeUs)); + output.append(") | Samples: "_s); + output.append(stats->selfSamples); + output.append('\n'); + + if (!stats->callers.isEmpty()) { + output.append("\n**Called by:**\n"_s); + WTF::Vector> sortedCallers; + for (auto& c : stats->callers) + sortedCallers.append({ c.key, c.value }); + std::sort(sortedCallers.begin(), sortedCallers.end(), [](const auto& a, const auto& b) { + return a.second > b.second; + }); + for (auto& [callerKey, count] : sortedCallers) { + output.append("- "_s); + // Extract just the function name from "funcNamelocation" + size_t sepPos = callerKey.find(kKeySeparator); + WTF::String callerName = (sepPos != WTF::notFound) ? callerKey.left(sepPos) : callerKey; + output.append(formatCodeSpan(callerName)); + output.append(" ("_s); + output.append(count); + output.append(")\n"_s); + } + } + + if (!stats->callees.isEmpty()) { + output.append("\n**Calls:**\n"_s); + WTF::Vector> sortedCallees; + for (auto& c : stats->callees) + sortedCallees.append({ c.key, c.value }); + std::sort(sortedCallees.begin(), sortedCallees.end(), [](const auto& a, const auto& b) { + return a.second > b.second; + }); + for (auto& [calleeKey, count] : sortedCallees) { + output.append("- "_s); + // Extract just the function name from "funcNamelocation" + size_t sepPos = calleeKey.find(kKeySeparator); + WTF::String calleeName = (sepPos != WTF::notFound) ? calleeKey.left(sepPos) : calleeKey; + output.append(formatCodeSpan(calleeName)); + output.append(" ("_s); + output.append(count); + output.append(")\n"_s); + } + } + + output.append('\n'); + } + + // Source files breakdown + WTF::HashMap fileTimesUs; + for (auto& [key, stats] : functionStatsMap) { + WTF::String file = stats.location; + size_t colonPos = file.reverseFind(':'); + if (colonPos != WTF::notFound && colonPos > 0) { + bool isLineNumber = true; + for (size_t i = colonPos + 1; i < file.length(); i++) { + if (file[i] < '0' || file[i] > '9') { + isLineNumber = false; + break; + } + } + if (isLineNumber) + file = file.left(colonPos); + } + fileTimesUs.add(file, 0).iterator->value += stats.selfTimeUs; + } + + WTF::Vector> sortedFiles; + for (auto& f : fileTimesUs) + sortedFiles.append({ f.key, f.value }); + std::sort(sortedFiles.begin(), sortedFiles.end(), [](const auto& a, const auto& b) { + return a.second > b.second; + }); + + output.append("## Files\n\n"_s); + output.append("| Self% | Self | File |\n"_s); + output.append("|------:|-----:|------|\n"_s); + + for (auto& [file, timeUs] : sortedFiles) { + if (timeUs == 0) + continue; + output.append("| "_s); + output.append(formatPercent(timeUs, totalTimeUs)); + output.append(" | "_s); + output.append(formatTime(timeUs)); + output.append(" | "_s); + output.append(formatCodeSpan(file)); + output.append(" |\n"_s); + } + + *outText = output.toString(); + } +} + } // namespace Bun extern "C" void Bun__startCPUProfiler(JSC::VM* vm) @@ -341,8 +1095,13 @@ extern "C" void Bun__startCPUProfiler(JSC::VM* vm) Bun::startCPUProfiler(*vm); } -extern "C" BunString Bun__stopCPUProfilerAndGetJSON(JSC::VM* vm) +extern "C" void Bun__stopCPUProfiler(JSC::VM* vm, BunString* outJSON, BunString* outText) { - WTF::String result = Bun::stopCPUProfilerAndGetJSON(*vm); - return Bun::toStringRef(result); + WTF::String jsonResult; + WTF::String textResult; + Bun::stopCPUProfiler(*vm, outJSON ? &jsonResult : nullptr, outText ? &textResult : nullptr); + if (outJSON) + *outJSON = Bun::toStringRef(jsonResult); + if (outText) + *outText = Bun::toStringRef(textResult); } diff --git a/src/bun.js/bindings/BunCPUProfiler.h b/src/bun.js/bindings/BunCPUProfiler.h index b5fd9f3fc2..e978360b29 100644 --- a/src/bun.js/bindings/BunCPUProfiler.h +++ b/src/bun.js/bindings/BunCPUProfiler.h @@ -16,8 +16,8 @@ bool isCPUProfilerRunning(); // Start the CPU profiler void startCPUProfiler(JSC::VM& vm); -// Stop the CPU profiler and convert to Chrome CPU profiler JSON format -// Returns JSON string, or empty string if profiler was never started -WTF::String stopCPUProfilerAndGetJSON(JSC::VM& vm); +// Stop the CPU profiler and get profile data in requested formats. +// Pass non-null pointers for the formats you want. Null pointers are skipped. +void stopCPUProfiler(JSC::VM& vm, WTF::String* outJSON, WTF::String* outText); } // namespace Bun diff --git a/src/bun.js/bindings/BunCPUProfiler.zig b/src/bun.js/bindings/BunCPUProfiler.zig index 231e0b556e..b17c53eb38 100644 --- a/src/bun.js/bindings/BunCPUProfiler.zig +++ b/src/bun.js/bindings/BunCPUProfiler.zig @@ -1,33 +1,51 @@ pub const CPUProfilerConfig = struct { name: []const u8, dir: []const u8, + md_format: bool = false, + json_format: bool = false, }; // C++ function declarations extern fn Bun__startCPUProfiler(vm: *jsc.VM) void; -extern fn Bun__stopCPUProfilerAndGetJSON(vm: *jsc.VM) bun.String; +extern fn Bun__stopCPUProfiler(vm: *jsc.VM, outJSON: ?*bun.String, outText: ?*bun.String) void; pub fn startCPUProfiler(vm: *jsc.VM) void { Bun__startCPUProfiler(vm); } pub fn stopAndWriteProfile(vm: *jsc.VM, config: CPUProfilerConfig) !void { - const json_string = Bun__stopCPUProfilerAndGetJSON(vm); - defer json_string.deref(); + var json_string: bun.String = .empty; + var text_string: bun.String = .empty; - if (json_string.isEmpty()) { - // No profile data or profiler wasn't started - return; + // Call the unified C++ function with pointers for requested formats + Bun__stopCPUProfiler( + vm, + if (config.json_format) &json_string else null, + if (config.md_format) &text_string else null, + ); + defer json_string.deref(); + defer text_string.deref(); + + // Write JSON format if requested and not empty + if (config.json_format and !json_string.isEmpty()) { + try writeProfileToFile(json_string, config, false); } - const json_slice = json_string.toUTF8(bun.default_allocator); - defer json_slice.deinit(); + // Write text format if requested and not empty + if (config.md_format and !text_string.isEmpty()) { + try writeProfileToFile(text_string, config, true); + } +} + +fn writeProfileToFile(profile_string: bun.String, config: CPUProfilerConfig, is_md_format: bool) !void { + const profile_slice = profile_string.toUTF8(bun.default_allocator); + defer profile_slice.deinit(); // Determine the output path using AutoAbsPath var path_buf: bun.AutoAbsPath = .initTopLevelDir(); defer path_buf.deinit(); - try buildOutputPath(&path_buf, config); + try buildOutputPath(&path_buf, config, is_md_format); // Convert to OS-specific path (UTF-16 on Windows, UTF-8 elsewhere) var path_buf_os: bun.OSPathBuffer = undefined; @@ -37,7 +55,7 @@ pub fn stopAndWriteProfile(vm: *jsc.VM, config: CPUProfilerConfig) !void { path_buf.sliceZ(); // Write the profile to disk using bun.sys.File.writeFile - const result = bun.sys.File.writeFile(bun.FD.cwd(), output_path_os, json_slice.slice()); + const result = bun.sys.File.writeFile(bun.FD.cwd(), output_path_os, profile_slice.slice()); if (result.asErr()) |err| { // If we got ENOENT, PERM, or ACCES, try creating the directory and retry const errno = err.getErrno(); @@ -45,7 +63,7 @@ pub fn stopAndWriteProfile(vm: *jsc.VM, config: CPUProfilerConfig) !void { if (config.dir.len > 0) { bun.makePath(bun.FD.cwd().stdDir(), config.dir) catch {}; // Retry write - const retry_result = bun.sys.File.writeFile(bun.FD.cwd(), output_path_os, json_slice.slice()); + const retry_result = bun.sys.File.writeFile(bun.FD.cwd(), output_path_os, profile_slice.slice()); if (retry_result.asErr()) |_| { return error.WriteFailed; } @@ -58,13 +76,22 @@ pub fn stopAndWriteProfile(vm: *jsc.VM, config: CPUProfilerConfig) !void { } } -fn buildOutputPath(path: *bun.AutoAbsPath, config: CPUProfilerConfig) !void { +fn buildOutputPath(path: *bun.AutoAbsPath, config: CPUProfilerConfig, is_md_format: bool) !void { // Generate filename var filename_buf: bun.PathBuffer = undefined; - const filename = if (config.name.len > 0) - config.name - else - try generateDefaultFilename(&filename_buf); + + // If both formats are being written and a custom name was specified, + // we need to add the appropriate extension to disambiguate + const has_both_formats = config.md_format and config.json_format; + const filename = if (config.name.len > 0) blk: { + if (has_both_formats) { + // Custom name with both formats - append extension based on format + const ext = if (is_md_format) ".md" else ".cpuprofile"; + break :blk std.fmt.bufPrint(&filename_buf, "{s}{s}", .{ config.name, ext }) catch return error.FilenameTooLong; + } else { + break :blk config.name; + } + } else try generateDefaultFilename(&filename_buf, is_md_format); // Append directory if specified if (config.dir.len > 0) { @@ -75,8 +102,8 @@ fn buildOutputPath(path: *bun.AutoAbsPath, config: CPUProfilerConfig) !void { path.append(filename); } -fn generateDefaultFilename(buf: *bun.PathBuffer) ![]const u8 { - // Generate filename like: CPU.{timestamp}.{pid}.cpuprofile +fn generateDefaultFilename(buf: *bun.PathBuffer, md_format: bool) ![]const u8 { + // Generate filename like: CPU.{timestamp}.{pid}.cpuprofile (or .md for markdown format) // Use microsecond timestamp for uniqueness const timespec = bun.timespec.now(.force_real_time); const pid = if (bun.Environment.isWindows) @@ -86,10 +113,13 @@ fn generateDefaultFilename(buf: *bun.PathBuffer) ![]const u8 { const epoch_microseconds: u64 = @intCast(timespec.sec *% 1_000_000 +% @divTrunc(timespec.nsec, 1000)); - return try std.fmt.bufPrint(buf, "CPU.{d}.{d}.cpuprofile", .{ + const extension = if (md_format) ".md" else ".cpuprofile"; + + return std.fmt.bufPrint(buf, "CPU.{d}.{d}{s}", .{ epoch_microseconds, pid, - }); + extension, + }) catch return error.FilenameTooLong; } const std = @import("std"); diff --git a/src/bun.js/bindings/JSInspectorProfiler.cpp b/src/bun.js/bindings/JSInspectorProfiler.cpp index 1ec1541e6f..4892266728 100644 --- a/src/bun.js/bindings/JSInspectorProfiler.cpp +++ b/src/bun.js/bindings/JSInspectorProfiler.cpp @@ -19,7 +19,8 @@ JSC_DECLARE_HOST_FUNCTION(jsFunction_stopCPUProfiler); JSC_DEFINE_HOST_FUNCTION(jsFunction_stopCPUProfiler, (JSGlobalObject * globalObject, CallFrame*)) { auto& vm = globalObject->vm(); - auto result = Bun::stopCPUProfilerAndGetJSON(vm); + WTF::String result; + Bun::stopCPUProfiler(vm, &result, nullptr); return JSValue::encode(jsString(vm, result)); } diff --git a/src/cli.zig b/src/cli.zig index ecdd54da86..3a0819a73f 100644 --- a/src/cli.zig +++ b/src/cli.zig @@ -392,6 +392,8 @@ pub const Command = struct { enabled: bool = false, name: ?[]const u8 = null, dir: ?[]const u8 = null, + md_format: bool = false, + json_format: bool = false, } = .{}, }; diff --git a/src/cli/Arguments.zig b/src/cli/Arguments.zig index 73f57628e5..f3c3c299da 100644 --- a/src/cli/Arguments.zig +++ b/src/cli/Arguments.zig @@ -90,6 +90,7 @@ pub const runtime_params_ = [_]ParamType{ clap.parseParam("--cpu-prof Start CPU profiler and write profile to disk on exit") catch unreachable, clap.parseParam("--cpu-prof-name Specify the name of the CPU profile file") catch unreachable, clap.parseParam("--cpu-prof-dir Specify the directory where the CPU profile will be saved") catch unreachable, + clap.parseParam("--cpu-prof-md Output CPU profile in markdown format (grep-friendly, designed for LLM analysis)") catch unreachable, clap.parseParam("--if-present Exit without an error if the entrypoint does not exist") catch unreachable, clap.parseParam("--no-install Disable auto install in the Bun runtime") catch unreachable, clap.parseParam("--install Configure auto-install behavior. One of \"auto\" (default, auto-installs when no node_modules), \"fallback\" (missing packages only), \"force\" (always).") catch unreachable, @@ -834,7 +835,13 @@ pub fn parse(allocator: std.mem.Allocator, ctx: Command.Context, comptime cmd: C bun.jsc.RuntimeTranspilerCache.is_disabled = true; } - if (args.flag("--cpu-prof")) { + const cpu_prof_flag = args.flag("--cpu-prof"); + const cpu_prof_md_flag = args.flag("--cpu-prof-md"); + + // --cpu-prof-md alone enables profiling with markdown format + // --cpu-prof alone enables profiling with JSON format + // Both flags together enable profiling with both formats + if (cpu_prof_flag or cpu_prof_md_flag) { ctx.runtime_options.cpu_prof.enabled = true; if (args.option("--cpu-prof-name")) |name| { ctx.runtime_options.cpu_prof.name = name; @@ -842,13 +849,17 @@ pub fn parse(allocator: std.mem.Allocator, ctx: Command.Context, comptime cmd: C if (args.option("--cpu-prof-dir")) |dir| { ctx.runtime_options.cpu_prof.dir = dir; } + // md_format is true if --cpu-prof-md is passed (regardless of --cpu-prof) + ctx.runtime_options.cpu_prof.md_format = cpu_prof_md_flag; + // json_format is true if --cpu-prof is passed (regardless of --cpu-prof-md) + ctx.runtime_options.cpu_prof.json_format = cpu_prof_flag; } else { - // Warn if --cpu-prof-name or --cpu-prof-dir is used without --cpu-prof + // Warn if --cpu-prof-name or --cpu-prof-dir is used without a profiler flag if (args.option("--cpu-prof-name")) |_| { - Output.warn("--cpu-prof-name requires --cpu-prof to be enabled", .{}); + Output.warn("--cpu-prof-name requires --cpu-prof or --cpu-prof-md to be enabled", .{}); } if (args.option("--cpu-prof-dir")) |_| { - Output.warn("--cpu-prof-dir requires --cpu-prof to be enabled", .{}); + Output.warn("--cpu-prof-dir requires --cpu-prof or --cpu-prof-md to be enabled", .{}); } } diff --git a/test/cli/run/cpu-prof.test.ts b/test/cli/run/cpu-prof.test.ts index a2172ab704..895c7aefc4 100644 --- a/test/cli/run/cpu-prof.test.ts +++ b/test/cli/run/cpu-prof.test.ts @@ -187,4 +187,221 @@ describe.concurrent("--cpu-prof", () => { expect(functionNames.some((name: string) => name !== "(root)" && name !== "(program)")).toBe(true); expect(exitCode).toBe(0); }); + + test("--cpu-prof-md generates markdown format profile", async () => { + using dir = tempDir("cpu-prof-md", { + "test.js": ` + // CPU-intensive task for text profile + function fibonacci(n) { + if (n <= 1) return n; + return fibonacci(n - 1) + fibonacci(n - 2); + } + + function main() { + const now = performance.now(); + while (now + 50 > performance.now()) { + Bun.inspect(fibonacci(20)); + } + } + + main(); + `, + }); + + await using proc = Bun.spawn({ + cmd: [bunExe(), "--cpu-prof", "--cpu-prof-md", "test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "inherit", + stderr: "inherit", + }); + + const exitCode = await proc.exited; + + // Check that a .md file was created (not .cpuprofile) + const files = readdirSync(String(dir)); + const mdFiles = files.filter(f => f.endsWith(".md") && f.startsWith("CPU.")); + + expect(mdFiles.length).toBeGreaterThan(0); + expect(exitCode).toBe(0); + + // Read and validate the markdown profile format + const profilePath = join(String(dir), mdFiles[0]); + const profileContent = readFileSync(profilePath, "utf-8"); + + // Validate the markdown format has expected sections + expect(profileContent).toContain("# CPU Profile"); + expect(profileContent).toContain("## Hot Functions (Self Time)"); + expect(profileContent).toContain("## Call Tree (Total Time)"); + expect(profileContent).toContain("## Function Details"); + expect(profileContent).toContain("## Files"); + + // Validate header contains summary info in markdown table + expect(profileContent).toMatch(/\| Duration \| Samples \| Interval \| Functions \|/); + + // Validate function details have caller/callee info + expect(profileContent).toContain("**Called by:**"); + expect(profileContent).toContain("**Calls:**"); + }); + + test("--cpu-prof-md with custom name", async () => { + using dir = tempDir("cpu-prof-md-name", { + "test.js": ` + function loop() { + const end = Date.now() + 32; + while (Date.now() < end) {} + } + loop(); + `, + }); + + const customName = "my-profile.md"; + + // --cpu-prof-md works standalone, no need for --cpu-prof + await using proc = Bun.spawn({ + cmd: [bunExe(), "--cpu-prof-md", "--cpu-prof-name", customName, "test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "inherit", + stderr: "inherit", + }); + + const exitCode = await proc.exited; + + const files = readdirSync(String(dir)); + expect(files).toContain(customName); + expect(exitCode).toBe(0); + + // Validate it's markdown format + const profileContent = readFileSync(join(String(dir), customName), "utf-8"); + expect(profileContent).toContain("# CPU Profile"); + }); + + test("--cpu-prof-md shows function details with relationships", async () => { + using dir = tempDir("cpu-prof-md-details", { + "test.js": ` + function workA() { + let sum = 0; + for (let i = 0; i < 500000; i++) sum += i; + return sum; + } + function workB() { + let sum = 0; + for (let i = 0; i < 500000; i++) sum += i; + return sum; + } + function main() { + const now = performance.now(); + while (now + 50 > performance.now()) { + workA(); + workB(); + } + } + main(); + `, + }); + + // --cpu-prof-md works standalone + await using proc = Bun.spawn({ + cmd: [bunExe(), "--cpu-prof-md", "test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "inherit", + stderr: "inherit", + }); + + const exitCode = await proc.exited; + expect(exitCode).toBe(0); + + const files = readdirSync(String(dir)); + const mdFiles = files.filter(f => f.endsWith(".md") && f.startsWith("CPU.")); + expect(mdFiles.length).toBeGreaterThan(0); + + const profileContent = readFileSync(join(String(dir), mdFiles[0]), "utf-8"); + + // Check markdown sections + expect(profileContent).toMatch(/## Hot Functions \(Self Time\)/); + expect(profileContent).toMatch(/## Call Tree \(Total Time\)/); + expect(profileContent).toMatch(/## Function Details/); + expect(profileContent).toMatch(/## Files/); + + // Check function detail headers (### `functionName`) + expect(profileContent).toMatch(/^### `/m); + }); + + test("--cpu-prof-md works standalone without --cpu-prof", async () => { + using dir = tempDir("cpu-prof-md-standalone", { + "test.js": ` + function loop() { + const end = Date.now() + 32; + while (Date.now() < end) {} + } + loop(); + `, + }); + + // Use ONLY --cpu-prof-md without --cpu-prof + await using proc = Bun.spawn({ + cmd: [bunExe(), "--cpu-prof-md", "test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "inherit", + stderr: "inherit", + }); + + const exitCode = await proc.exited; + + // Check that a .md file was created + const files = readdirSync(String(dir)); + const mdFiles = files.filter(f => f.endsWith(".md") && f.startsWith("CPU.")); + + expect(mdFiles.length).toBeGreaterThan(0); + expect(exitCode).toBe(0); + + // Validate it's the markdown format + const profileContent = readFileSync(join(String(dir), mdFiles[0]), "utf-8"); + expect(profileContent).toContain("# CPU Profile"); + }); + + test("--cpu-prof and --cpu-prof-md together creates both files", async () => { + using dir = tempDir("cpu-prof-both-formats", { + "test.js": ` + function loop() { + const end = Date.now() + 32; + while (Date.now() < end) {} + } + loop(); + `, + }); + + // Use both flags together + await using proc = Bun.spawn({ + cmd: [bunExe(), "--cpu-prof", "--cpu-prof-md", "test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "inherit", + stderr: "inherit", + }); + + const exitCode = await proc.exited; + + // Check that both .cpuprofile and .md files were created + const files = readdirSync(String(dir)); + const jsonFiles = files.filter(f => f.endsWith(".cpuprofile")); + const mdFiles = files.filter(f => f.endsWith(".md") && f.startsWith("CPU.")); + + expect(jsonFiles.length).toBeGreaterThan(0); + expect(mdFiles.length).toBeGreaterThan(0); + expect(exitCode).toBe(0); + + // Validate JSON file + const jsonContent = readFileSync(join(String(dir), jsonFiles[0]), "utf-8"); + const profile = JSON.parse(jsonContent); + expect(profile).toHaveProperty("nodes"); + expect(profile).toHaveProperty("samples"); + + // Validate markdown file + const mdContent = readFileSync(join(String(dir), mdFiles[0]), "utf-8"); + expect(mdContent).toContain("# CPU Profile"); + }); });