diff --git a/bindings/profilers/wall.cc b/bindings/profilers/wall.cc index 32e8ef7a..c08ab094 100644 --- a/bindings/profilers/wall.cc +++ b/bindings/profilers/wall.cc @@ -511,7 +511,8 @@ void WallProfiler::Cleanup(Isolate* isolate) { ContextsByNode WallProfiler::GetContextsByNode(CpuProfile* profile, ContextBuffer& contexts, - int64_t startCpuTime) { + int64_t startCpuTime, + int64_t V8toEpochOffset) { ContextsByNode contextsByNode; auto sampleCount = profile->GetSamplesCount(); @@ -551,7 +552,6 @@ ContextsByNode WallProfiler::GetContextsByNode(CpuProfile* profile, return object; }; #endif - auto V8toEpochOffset = GetV8ToEpochOffset(); auto lastCpuTime = startCpuTime; // skip first sample because it's the one taken on profiler start, outside of @@ -1160,6 +1160,9 @@ Result WallProfiler::StopCore(bool restart, ProfileBuilder&& buildProfile) { ContextsByNode* contextsByNodePtr = nullptr; int64_t nonJSThreadsCpuTime = 0; bool hasCpuTime = false; + // One offset for both the sample timestamps and the profile's epochOffset, + // so that they agree. + auto v8ToEpochOffset = GetV8ToEpochOffset(); if (withContexts_) { if (isMainThread_ && collectCpuTime_) { @@ -1173,13 +1176,17 @@ Result WallProfiler::StopCore(bool restart, ProfileBuilder&& buildProfile) { std::max(processCpu - totalWorkerCpu, ProcessCpuClock::duration{}) .count(); } - contextsByNode = - GetContextsByNode(v8_profile, contexts, startThreadCpuTime); + contextsByNode = GetContextsByNode( + v8_profile, contexts, startThreadCpuTime, v8ToEpochOffset); contextsByNodePtr = &contextsByNode; hasCpuTime = collectCpuTime_; } - buildProfile(v8_profile, hasCpuTime, nonJSThreadsCpuTime, contextsByNodePtr); + buildProfile(v8_profile, + hasCpuTime, + nonJSThreadsCpuTime, + contextsByNodePtr, + v8ToEpochOffset); v8_profile->Delete(); @@ -1197,17 +1204,28 @@ Result WallProfiler::StopCore(bool restart, ProfileBuilder&& buildProfile) { return {}; } +// Sets the offset that converts the profile's V8 timer values (startTime, +// endTime) to microseconds since the UNIX epoch, like sample timestamps. +static void SetEpochOffset(v8::Local profile, + int64_t v8ToEpochOffset) { + Nan::Set(profile.As(), + Nan::New("epochOffset").ToLocalChecked(), + Nan::New(static_cast(v8ToEpochOffset))); +} + Result WallProfiler::StopImpl(bool restart, v8::Local& profile) { return StopCore(restart, [&](const v8::CpuProfile* v8_profile, bool hasCpuTime, int64_t nonJSThreadsCpuTime, - ContextsByNode* contextsByNodePtr) { + ContextsByNode* contextsByNodePtr, + int64_t v8ToEpochOffset) { profile = TranslateTimeProfile(v8_profile, includeLines_, contextsByNodePtr, hasCpuTime, nonJSThreadsCpuTime); + SetEpochOffset(profile, v8ToEpochOffset); }); } @@ -1219,11 +1237,13 @@ Result WallProfiler::StopAndCollectImpl(bool restart, [&](const v8::CpuProfile* v8_profile, bool hasCpuTime, int64_t nonJSThreadsCpuTime, - ContextsByNode* contextsByNodePtr) { + ContextsByNode* contextsByNodePtr, + int64_t v8ToEpochOffset) { auto* isolate = Isolate::GetCurrent(); TimeProfileViewState state{includeLines_, contextsByNodePtr, {}}; auto profile_view = BuildTimeProfileView( v8_profile, hasCpuTime, nonJSThreadsCpuTime, state); + SetEpochOffset(profile_view, v8ToEpochOffset); v8::Local argv[] = {profile_view}; auto cb_result = Nan::Call( callback, isolate->GetCurrentContext()->Global(), 1, argv); diff --git a/bindings/profilers/wall.hh b/bindings/profilers/wall.hh index 5fdf0d22..d44f87a1 100644 --- a/bindings/profilers/wall.hh +++ b/bindings/profilers/wall.hh @@ -128,7 +128,8 @@ class WallProfiler : public Nan::ObjectWrap { ContextsByNode GetContextsByNode(v8::CpuProfile* profile, ContextBuffer& contexts, - int64_t startCpuTime); + int64_t startCpuTime, + int64_t v8ToEpochOffset); bool waitForSignal(uint64_t targetCallCount = 0); static void CleanupHook(void* data); diff --git a/ts/src/heap-profiler.ts b/ts/src/heap-profiler.ts index dfc15e27..447b88d8 100644 --- a/ts/src/heap-profiler.ts +++ b/ts/src/heap-profiler.ts @@ -28,6 +28,7 @@ import { DEFAULT_COLUMN_NUMBERS, serializeHeapProfile, } from './profile-serializer'; +import {NormalizedProfile, normalizeHeapProfile} from './profile-normalizer'; import {SourceMapper} from './sourcemapper/sourcemapper'; import { AllocationProfileNode, @@ -103,6 +104,31 @@ export function profile( ); } +/** + * Collects a profile and returns it normalized into a format-neutral + * representation. Throws if heap profiler is not enabled. + */ +export function normalizedProfile( + ignoreSamplePath?: string, + sourceMapper?: SourceMapper, + generateLabels?: GenerateAllocationLabelsFunction, +): NormalizedProfile { + return collectProfile(root => { + const startTimeNanos = BigInt(Date.now()) * 1_000_000n; + return normalizeHeapProfile( + addExternalMemoryNode(root, startedWithAllocations), + { + startTimeNanos, + intervalBytes: heapIntervalBytes, + ignoreSamplesPath: ignoreSamplePath, + sourceMapper, + generateLabels, + allocations: startedWithAllocations, + }, + ); + }); +} + function collectProfile( processProfile: ( root: AllocationProfileNode | AllocationProfileNodeWithStats, @@ -134,48 +160,9 @@ export function convertProfile( columnNumbers: ColumnNumbers = DEFAULT_COLUMN_NUMBERS, ): Profile { const allocations = startedWithAllocations; - const startTimeNanos = Date.now() * 1000 * 1000; - // Add node for external memory usage. - // Current type definitions do not have external. - // TODO: remove any once type definition is updated to include external. - // eslint-disable-next-line @typescript-eslint/no-explicit-any - const {external}: {external: number} = process.memoryUsage() as any; - let root: AllocationProfileNode | AllocationProfileNodeWithStats; - if (external > 0) { - if (allocations) { - const externalNode: AllocationProfileNodeWithStats = { - name: '(external)', - scriptName: '', - children: [], - allocations: [ - { - inuseObjects: 1, - inuseSpaceBytes: external, - allocObjects: 1, - allocSpaceBytes: external, - }, - ], - }; - const allocationRoot = rootNode as AllocationProfileNodeWithStats; - root = { - ...allocationRoot, - children: [...allocationRoot.children, externalNode], - }; - } else { - const externalNode: AllocationProfileNode = { - name: '(external)', - scriptName: '', - children: [], - allocations: [{sizeBytes: external, count: 1}], - }; - const heapRoot = rootNode as AllocationProfileNode; - root = {...heapRoot, children: [...heapRoot.children, externalNode]}; - } - } else { - root = rootNode; - } + const startTimeNanos = BigInt(Date.now()) * 1_000_000n; return serializeHeapProfile( - root, + addExternalMemoryNode(rootNode, allocations), startTimeNanos, heapIntervalBytes, ignoreSamplePath, @@ -186,6 +173,51 @@ export function convertProfile( ); } +/** + * Returns the profile with a node for external memory usage added under the + * root, if there is any external memory. Does not modify the input. + */ +function addExternalMemoryNode( + rootNode: AllocationProfileNode | AllocationProfileNodeWithStats, + allocations: boolean, +): AllocationProfileNode | AllocationProfileNodeWithStats { + // Current type definitions do not have external. + // TODO: remove any once type definition is updated to include external. + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const {external}: {external: number} = process.memoryUsage() as any; + if (external <= 0) { + return rootNode; + } + if (allocations) { + const externalNode: AllocationProfileNodeWithStats = { + name: '(external)', + scriptName: '', + children: [], + allocations: [ + { + inuseObjects: 1, + inuseSpaceBytes: external, + allocObjects: 1, + allocSpaceBytes: external, + }, + ], + }; + const allocationRoot = rootNode as AllocationProfileNodeWithStats; + return { + ...allocationRoot, + children: [...allocationRoot.children, externalNode], + }; + } + const externalNode: AllocationProfileNode = { + name: '(external)', + scriptName: '', + children: [], + allocations: [{sizeBytes: external, count: 1}], + }; + const heapRoot = rootNode as AllocationProfileNode; + return {...heapRoot, children: [...heapRoot.children, externalNode]}; +} + /** * Collects a profile and returns it serialized in pprof format using lazy V2 API. * Throws if heap profiler is not enabled. diff --git a/ts/src/index.ts b/ts/src/index.ts index 10d2052b..cf1ca01e 100644 --- a/ts/src/index.ts +++ b/ts/src/index.ts @@ -24,7 +24,26 @@ export { TimeProfileNode, ProfileNode, LabelSet, + TimeProfile, } from './v8-types'; +export { + Frame, + frameFunctionName, + HeapProfileNormalizerOptions, + NormalizedProfile, + NormalizedSample, + normalizeHeapProfile, + normalizeTimeProfile, + ProfileMetadata, + ProfileVisitor, + SampleLabel, + SampleLabelValue, + SampleType, + TimeProfileNormalizerOptions, + visitHeapProfile, + visitTimeProfile, + VisitResult, +} from './profile-normalizer'; export {HeapLimitExtensionSize} from './heap-profiler'; @@ -37,6 +56,8 @@ export const time = { profile: timeProfiler.profile, start: timeProfiler.start, stop: timeProfiler.stop, + stopNormalized: timeProfiler.stopNormalized, + stopRaw: timeProfiler.stopRaw, profileV2: timeProfiler.profileV2, getContext: timeProfiler.getContext, setContext: timeProfiler.setContext, @@ -54,6 +75,7 @@ export const heap = { stop: heapProfiler.stop, profile: heapProfiler.profile, profileV2: heapProfiler.profileV2, + normalizedProfile: heapProfiler.normalizedProfile, convertProfile: heapProfiler.convertProfile, v8Profile: heapProfiler.v8Profile, monitorOutOfMemory: heapProfiler.monitorOutOfMemory, diff --git a/ts/src/profile-normalizer.ts b/ts/src/profile-normalizer.ts new file mode 100644 index 00000000..2f023940 --- /dev/null +++ b/ts/src/profile-normalizer.ts @@ -0,0 +1,771 @@ +/** + * Copyright 2026 Datadog. All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +/** + * Format-neutral normalization of V8 profiles. + * + * Turns the raw V8 time and heap profile trees into a stream of resolved + * frames and samples, applying everything that is a matter of profile + * semantics rather than of any particular output format: source mapping, + * synthetic runtime frames, per-context sample expansion, CPU time + * attribution, label generation and sample values. Output formats (pprof in + * profile-serializer.ts, and potentially others) are implemented as + * {@link ProfileVisitor}s on top of it. + */ + +import { + GeneratedLocation, + SourceLocation, + SourceMapper, +} from './sourcemapper/sourcemapper'; +import { + Allocation, + AllocationWithStats, + AllocationProfileNode, + AllocationProfileNodeWithStats, + GenerateAllocationLabelsFunction, + GenerateTimeLabelsFunction, + ProfileNode, + TimeProfile, + TimeProfileNode, +} from './v8-types'; + +export const NON_JS_THREADS_FUNCTION_NAME = 'Non JS threads activity'; +export const GARBAGE_COLLECTION_FUNCTION_NAME = 'Garbage Collection'; + +/** + * A resolved stack frame: `file://` prefix stripped and source map applied. + */ +export interface Frame { + /** + * Function name after source mapping. Empty or absent for anonymous + * functions; use {@link frameFunctionName} to get a display name. + */ + name?: string; + file: string; + line?: number; + column?: number; + scriptId?: number; + /** + * True when the frame's script declares a sourceMappingURL but the map + * could not be found locally, i.e. the frame is a candidate for server-side + * unminification. + */ + missingMapFile: boolean; +} + +export type SampleLabelValue = string | number | bigint; + +/** A label as a key/value pair. */ +export type SampleLabel = [key: string, value: SampleLabelValue]; + +export interface NormalizedSample { + /** The stack, as the ID returned by {@link ProfileVisitor.stack}. */ + stackId: number; + /** One value for each of {@link ProfileMetadata.sampleTypes}. */ + values: number[]; + labels: SampleLabel[]; + /** + * Time at which the sample was taken, in nanoseconds since epoch (with + * microsecond precision). Only set on samples that represent a single + * observation with a known time, i.e. time profile samples for a context. + * Undefined for aggregated samples. + */ + timestamp?: bigint; +} + +export interface SampleType { + type: string; + unit: string; +} + +export interface ProfileMetadata { + sampleTypes: SampleType[]; + periodType: SampleType; + period: number; + /** + * Time of collection in nanoseconds since epoch: when the profile was + * normalized. A bigint, because the value exceeds Number.MAX_SAFE_INTEGER. + */ + timeNanos: bigint; + /** + * Start of the profile's collection period, in nanoseconds since epoch, + * for profiles collected over a period (time profiles). Sample timestamps + * fall within [startTimeNanos, startTimeNanos + durationNanos]. + */ + startTimeNanos?: bigint; + durationNanos?: number; +} + +/** + * Receives a normalized profile. Calls arrive in this order: metadata() once, + * then frame(), stack() and sample() interleaved, then end() once. Each distinct frame and + * stack is delivered exactly once, before the first stack or sample that + * references it. Only stacks that have samples are delivered. + * + * All samples of a profile tree node are delivered consecutively. A stack ID + * normally belongs to a single node, but can recur later if two nodes resolve + * to the same frames (e.g. when source maps map distinct generated locations + * to the same original location). + */ +export interface ProfileVisitor { + metadata(metadata: ProfileMetadata): void; + /** + * @returns the ID by which stacks will refer to this frame. + */ + frame(frame: Frame): number; + /** + * @param frameIds - the stack, leaf first, as IDs returned by frame(). The + * array is not reused by the caller, so the visitor may retain it. + * @returns the ID by which samples will refer to this stack. + */ + stack(frameIds: number[]): number; + sample(sample: NormalizedSample): void; + /** Called after the last sample, with what the visit found. */ + end?(result: VisitResult): void; +} + +export interface VisitResult { + /** True if at least one frame has {@link Frame.missingMapFile} set. */ + hasMissingMapFiles: boolean; +} + +/** A normalized profile collected into arrays. */ +export interface NormalizedProfile extends ProfileMetadata, VisitResult { + frames: Frame[]; + /** Stacks, leaf first, as indices into {@link frames}. */ + stacks: number[][]; + /** Samples' stack IDs are indices into {@link stacks}. */ + samples: NormalizedSample[]; +} + +export interface TimeProfileNormalizerOptions { + /** Average time in microseconds between samples, as requested. */ + intervalMicros: number; + sourceMapper?: SourceMapper; + /** + * Recompute the sampling interval from the profile duration and total hit + * count, bounded to [intervalMicros, 2 * intervalMicros]. + */ + recomputeSamplingInterval?: boolean; + generateLabels?: GenerateTimeLabelsFunction; + /** + * Emit a separate, timestamped sample for every context, even when it has + * no labels. By default, the hits and CPU time of contexts without labels + * are aggregated into a single sample per node, without a timestamp. Set + * this when every sample should have a timestamp, e.g. for OTel profiles, + * whose samples should all have the same shape. Hits without a context + * (e.g. when contexts are not collected) are still aggregated. + */ + samplePerContext?: boolean; +} + +export interface HeapProfileNormalizerOptions { + /** Start time of profile, in nanoseconds since epoch. */ + startTimeNanos: bigint; + /** Bytes allocated between samples. */ + intervalBytes: number; + ignoreSamplesPath?: string; + sourceMapper?: SourceMapper; + generateLabels?: GenerateAllocationLabelsFunction; + /** Root was collected in allocation mode (nodes carry allocation stats). */ + allocations?: boolean; +} + +/** + * Emits a sample for the node currently being visited. + */ +type EmitSample = ( + values: number[], + labels: SampleLabel[], + timestamp?: bigint, +) => void; + +/** + * Converts a node into zero or more samples and passes them to emit. + */ +type EmitSamples = (node: T, emit: EmitSample) => void; + +/** + * Profile node and the interned stack of its parent (-1 for top level nodes). + */ +interface Entry { + node: T; + parentStack: number; +} + +function isGeneratedLocation( + location: SourceLocation, +): location is GeneratedLocation { + return ( + location.column !== undefined && + location.line !== undefined && + location.line > 0 + ); +} + +/** + * @returns the frame's function name, or a synthesized + * `(anonymous:L#line:C#column)` name for anonymous functions. + */ +export function frameFunctionName(frame: Frame): string { + if (frame.name) { + return frame.name; + } + if (frame.line) { + if (frame.column) { + return `(anonymous:L#${frame.line}:C#${frame.column})`; + } + return `(anonymous:L#${frame.line})`; + } + return '(anonymous)'; +} + +function toSampleLabels(labelSet: object): SampleLabel[] { + const labels: SampleLabel[] = []; + // A for...in loop doesn't allocate the entries array of Object.entries() + for (const key in labelSet) { + if (!Object.prototype.hasOwnProperty.call(labelSet, key)) continue; + const value = (labelSet as Record)[key]; + switch (typeof value) { + case 'string': + case 'number': + case 'bigint': + labels.push([key, value]); + break; + } + } + return labels; +} + +function requireAllocationStat( + value: number | undefined, + field: string, +): number { + if (value === undefined) { + throw new Error(`Allocation profile is missing ${field}.`); + } + return value; +} + +/** + * Walks the V8 profile tree depth first, delivering each distinct frame and + * stack, and the samples emitted for each node to the visitor. + * + * Stacks are interned by prefix: a node's stack is identified by its parent's + * stack and its own frame ID, so stacks with equal frames get the same ID + * without comparing whole arrays. A stack is only materialized and delivered + * to the visitor when its first sample is emitted. + */ +function visitTree( + root: T, + visitor: ProfileVisitor, + emitSamples: EmitSamples, + ignoreSamplesPath?: string, + sourceMapper?: SourceMapper, +): VisitResult { + // Frames, by internal frame index: the visitor's frame ID. Indexed by the + // raw position (before source mapping), so a repeated position skips + // source mapping, and by resolved identity, so different positions that + // resolve to the same frame share it. + const frameIndexByPosition = new Map(); + const frameIndexByIdentity = new Map(); + const frameIds: number[] = []; + let hasMissingMapFiles = false; + + // Interned stacks, by internal stack index: the parent stack index (-1 for + // none), the internal frame index, the visitor's stack ID (undefined until + // delivered), and the child stacks by frame index. Top-level stacks are + // the children of rootStacks. + const stackParents: number[] = []; + const stackFrames: number[] = []; + const stackIds: Array = []; + const stackChildren: Array | undefined> = []; + const rootStacks = new Map(); + + let currentStack = -1; + const emit: EmitSample = (values, labels, timestamp) => { + visitor.sample({ + stackId: getStackId(currentStack), + values, + labels, + timestamp, + }); + }; + + const entries: Array> = (root.children as T[]).map((n: T) => ({ + node: n, + parentStack: -1, + })); + while (entries.length > 0) { + const entry = entries.pop()!; + const node = entry.node; + + // mjs files have a `file://` prefix in the scriptName -> remove it + const scriptName = node.scriptName.startsWith('file://') + ? node.scriptName.slice(7) + : node.scriptName; + + if (ignoreSamplesPath && scriptName.indexOf(ignoreSamplesPath) > -1) { + continue; + } + const stack = internStack( + entry.parentStack, + getFrameIndex(node, scriptName), + ); + currentStack = stack; + emitSamples(node, emit); + for (const child of node.children as T[]) { + entries.push({node: child, parentStack: stack}); + } + } + + const result = {hasMissingMapFiles}; + visitor.end?.(result); + return result; + + function internStack(parent: number, frame: number): number { + let children: Map | undefined; + if (parent < 0) { + children = rootStacks; + } else { + children = stackChildren[parent]; + if (children === undefined) { + children = new Map(); + stackChildren[parent] = children; + } + } + let stack = children.get(frame); + if (stack === undefined) { + stack = stackParents.length; + stackParents.push(parent); + stackFrames.push(frame); + stackIds.push(undefined); + stackChildren.push(undefined); + children.set(frame, stack); + } + return stack; + } + + function getStackId(stack: number): number { + let id = stackIds[stack]; + if (id === undefined) { + const stackFrameIds: number[] = []; + for (let s = stack; s !== -1; s = stackParents[s]) { + stackFrameIds.push(frameIds[stackFrames[s]]); + } + id = visitor.stack(stackFrameIds); + stackIds[stack] = id; + } + return id; + } + + function getFrameIndex(node: ProfileNode, scriptName: string): number { + // The script ID identifies a script in V8 profiles; without one, the + // script name has to. The name comes last, so the key is unambiguous. + const positionKey = + node.scriptId !== undefined + ? `${node.scriptId}:${node.lineNumber}:${node.columnNumber}:${node.name}` + : `:${scriptName.length}:${scriptName}:${node.lineNumber}:${node.columnNumber}:${node.name}`; + let index = frameIndexByPosition.get(positionKey); + if (index === undefined) { + index = resolveFrameIndex(node, scriptName); + frameIndexByPosition.set(positionKey, index); + } + return index; + } + + function resolveFrameIndex(node: ProfileNode, scriptName: string): number { + let loc: SourceLocation = { + file: scriptName || '', + line: node.lineNumber, + column: node.columnNumber, + name: node.name, + }; + + let mapped = false; + if (loc.line) { + if (sourceMapper && isGeneratedLocation(loc)) { + loc = sourceMapper.mappingInfo(loc); + mapped = true; + if (loc.missingMapFile) { + hasMissingMapFiles = true; + } + } + } + const file = loc.file || ''; + // An unmapped frame is identified by its position, which was just looked + // up. Source mapping can resolve different positions to the same frame, + // so a mapped frame needs to be looked up by its resolved identity. The + // resolved file is part of that: after source mapping, one script can map + // to several original files. The file's length makes the key unambiguous. + const keyStr = mapped + ? `${node.scriptId}:${loc.line}:${loc.column}:${loc.missingMapFile ? 1 : 0}:${file.length}:${file}:${loc.name}` + : undefined; + let index = + keyStr === undefined ? undefined : frameIndexByIdentity.get(keyStr); + if (index === undefined) { + index = frameIds.length; + frameIds.push( + visitor.frame({ + name: loc.name, + file, + line: loc.line, + column: loc.column, + scriptId: node.scriptId, + missingMapFile: loc.missingMapFile === true, + }), + ); + if (keyStr !== undefined) frameIndexByIdentity.set(keyStr, index); + } + return index; + } +} + +export function computeTotalHitCount(root: TimeProfileNode): number { + return ( + root.hitCount + + (root.children as TimeProfileNode[]).reduce( + (sum, node) => sum + computeTotalHitCount(node), + 0, + ) + ); +} + +/** Perform some modifications on time profile: + * - Add non-JS thread activity node if available + * - remove `(program)` nodes + * - remove `(idle)` nodes with no context + * - set `(idle)` nodes' wall time to zero when they have a context + * - Convert `(garbage collector)` node to `Garbage Collection` + * - Put `non-JS thread activity` node and `Garbage Collection` under a top level `Node.js` node + * This function does not change the input profile. + */ +function updateTimeProfile(prof: TimeProfile): TimeProfile { + const newTopLevelChildren: TimeProfileNode[] = []; + + let runtimeNode: TimeProfileNode | undefined; + + function getRuntimeNode(): TimeProfileNode { + if (!runtimeNode) { + runtimeNode = { + name: 'Node.js', + scriptName: '', + scriptId: 0, + lineNumber: 0, + columnNumber: 0, + children: [], + hitCount: 0, + }; + newTopLevelChildren.push(runtimeNode); + } + return runtimeNode; + } + + for (const child of prof.topDownRoot.children as TimeProfileNode[]) { + if (child.name === '(program)') { + continue; + } + if (child.name === '(idle)' && child.contexts?.length === 0) { + continue; + } + if (child.name === '(garbage collector)') { + // Create a new node to avoid modifying the input one + const newChild: TimeProfileNode = { + ...child, + name: GARBAGE_COLLECTION_FUNCTION_NAME, + }; + getRuntimeNode().children.push(newChild); + } else { + newTopLevelChildren.push(child); + } + } + + if (prof.hasCpuTime && prof.nonJSThreadsCpuTime) { + const node: TimeProfileNode = { + name: NON_JS_THREADS_FUNCTION_NAME, + scriptName: '', + scriptId: 0, + lineNumber: 0, + columnNumber: 0, + children: [], + hitCount: 0, // 0 because this should not be accounted for wall time + contexts: [ + { + context: {}, + timestamp: BigInt(0), + cpuTime: prof.nonJSThreadsCpuTime, + asyncId: -1, + }, + ], + }; + getRuntimeNode().children.push(node); + } + return { + ...prof, + topDownRoot: {...prof.topDownRoot, children: newTopLevelChildren}, + }; +} + +/** + * Normalizes a V8 time profile and passes it to the visitor. + * + * Sample values are [sample count, wall nanoseconds] plus CPU nanoseconds if + * the profile has CPU time. + */ +export function visitTimeProfile( + prof: TimeProfile, + visitor: ProfileVisitor, + options: TimeProfileNormalizerOptions, +): VisitResult { + const { + sourceMapper, + recomputeSamplingInterval, + generateLabels, + samplePerContext, + } = options; + let intervalMicros = options.intervalMicros; + // If requested, recompute sampling interval from profile duration and total number of hits, + // since profile duration should be #hits x interval. + // Recomputing an average interval is more accurate, since in practice intervals between + // samples are larger than the requested sampling interval (eg. 12.5ms vs 10ms requested). + // For very short durations, computation becomes meaningless (eg. if there is only one hit), + // therefore keep intervalMicros as a lower bound and 2 * intervalMicros as upper bound. + if (recomputeSamplingInterval) { + const totalHitCount = + prof.totalHitCount ?? computeTotalHitCount(prof.topDownRoot); + if (totalHitCount > 0) { + intervalMicros = Math.min( + Math.max( + Math.floor((prof.endTime - prof.startTime) / totalHitCount), + intervalMicros, + ), + 2 * intervalMicros, + ); + } + } + const intervalNanos = intervalMicros * 1000; + + const timeType = {type: 'wall', unit: 'nanoseconds'}; + const sampleTypes = [{type: 'sample', unit: 'count'}, timeType]; + if (prof.hasCpuTime) { + sampleTypes.push({type: 'cpu', unit: 'nanoseconds'}); + } + const timeNanos = BigInt(Date.now()) * 1_000_000n; + const durationNanos = (prof.endTime - prof.startTime) * 1000; + visitor.metadata({ + sampleTypes, + timeNanos, + // Exact with the native profiler's epoch offset. Without one, estimate it + // on the assumption that the profile was just stopped. + startTimeNanos: + prof.epochOffset !== undefined + ? BigInt(Math.round(prof.startTime + prof.epochOffset)) * 1000n + : timeNanos - BigInt(Math.round(durationNanos)), + durationNanos, + periodType: timeType, + period: intervalNanos, + }); + + const emitTimeSamples: EmitSamples = ( + node: TimeProfileNode, + emit: EmitSample, + ) => { + let unlabelledHits = node.hitCount; + let unlabelledCpuTime = 0; + const isIdle = node.name === '(idle)'; + for (const context of node.contexts || []) { + const labels = toSampleLabels( + generateLabels + ? generateLabels({node, context}) + : (context.context ?? {}), + ); + if (labels.length > 0 || samplePerContext) { + // Only assign wall time if there are hits, some special nodes such as `(Non-JS threads)` + // have zero hit count (since they do not count as wall time) and should not be assigned any + // wall time. Also, `(idle)` nodes should be assigned zero wall time. + const values = + unlabelledHits > 0 ? [1, isIdle ? 0 : intervalNanos] : [0, 0]; + if (prof.hasCpuTime) { + values.push(context.cpuTime ?? 0); + } + // Context timestamps are in microseconds; 0 marks a synthetic context. + emit( + values, + labels, + context.timestamp ? BigInt(context.timestamp) * 1000n : undefined, + ); + unlabelledHits--; + } else if (prof.hasCpuTime) { + unlabelledCpuTime += context.cpuTime ?? 0; + } + } + if ((!isIdle && unlabelledHits > 0) || unlabelledCpuTime > 0) { + const labels = generateLabels ? generateLabels({node}) : {}; + const values = + unlabelledHits > 0 + ? [unlabelledHits, isIdle ? 0 : unlabelledHits * intervalNanos] + : [0, 0]; + if (prof.hasCpuTime) { + values.push(unlabelledCpuTime); + } + emit(values, toSampleLabels(labels)); + } + }; + + return visitTree( + updateTimeProfile(prof).topDownRoot, + visitor, + emitTimeSamples, + undefined, + sourceMapper, + ); +} + +/** + * Normalizes a V8 heap profile and passes it to the visitor. + * + * Sample values are [inuse objects, inuse bytes], or [inuse objects, alloc + * objects, inuse bytes, alloc bytes] in allocation mode. + */ +export function visitHeapProfile( + prof: AllocationProfileNode | AllocationProfileNodeWithStats, + visitor: ProfileVisitor, + options: HeapProfileNormalizerOptions, +): VisitResult { + const {ignoreSamplesPath, sourceMapper, generateLabels, allocations} = + options; + + const sampleTypes = allocations + ? [ + {type: 'inuse_objects', unit: 'count'}, + {type: 'alloc_objects', unit: 'count'}, + {type: 'inuse_space', unit: 'bytes'}, + {type: 'alloc_space', unit: 'bytes'}, + ] + : [ + {type: 'inuse_objects', unit: 'count'}, + {type: 'inuse_space', unit: 'bytes'}, + ]; + visitor.metadata({ + sampleTypes, + timeNanos: options.startTimeNanos, + periodType: sampleTypes[sampleTypes.length - 1], + period: options.intervalBytes, + }); + + const emitHeapSamples: EmitSamples< + AllocationProfileNode | AllocationProfileNodeWithStats + > = ( + node: AllocationProfileNode | AllocationProfileNodeWithStats, + emit: EmitSample, + ) => { + if (node.allocations.length === 0) { + return; + } + const labels = generateLabels + ? toSampleLabels(generateLabels({node: node as AllocationProfileNode})) + : []; + for (const alloc of node.allocations) { + // Live heap only + if (!allocations) { + const heapAllocation = alloc as Allocation; + emit( + [ + heapAllocation.count, + heapAllocation.sizeBytes * heapAllocation.count, + ], + labels, + // TODO: add tag for allocation size + ); + continue; + } + + const stats = alloc as AllocationWithStats; + const inuseObjects = requireAllocationStat( + stats.inuseObjects, + 'inuseObjects', + ); + const inuseSpaceBytes = requireAllocationStat( + stats.inuseSpaceBytes, + 'inuseSpaceBytes', + ); + const allocObjects = requireAllocationStat( + stats.allocObjects, + 'allocObjects', + ); + const allocSpaceBytes = requireAllocationStat( + stats.allocSpaceBytes, + 'allocSpaceBytes', + ); + emit( + [inuseObjects, allocObjects, inuseSpaceBytes, allocSpaceBytes], + labels, + // TODO: add tag for allocation size + ); + } + }; + + return visitTree( + prof, + visitor, + emitHeapSamples, + ignoreSamplesPath, + sourceMapper, + ); +} + +function collect( + visit: (visitor: ProfileVisitor) => VisitResult, +): NormalizedProfile { + let metadata: ProfileMetadata | undefined; + const frames: Frame[] = []; + const stacks: number[][] = []; + const samples: NormalizedSample[] = []; + const {hasMissingMapFiles} = visit({ + metadata: m => { + metadata = m; + }, + frame: f => frames.push(f) - 1, + stack: s => stacks.push(s) - 1, + sample: s => { + samples.push(s); + }, + }); + return {...metadata!, frames, stacks, samples, hasMissingMapFiles}; +} + +/** + * Normalizes a V8 time profile into a {@link NormalizedProfile}. + * See {@link visitTimeProfile}. + */ +export function normalizeTimeProfile( + prof: TimeProfile, + options: TimeProfileNormalizerOptions, +): NormalizedProfile { + return collect(visitor => visitTimeProfile(prof, visitor, options)); +} + +/** + * Normalizes a V8 heap profile into a {@link NormalizedProfile}. + * See {@link visitHeapProfile}. + */ +export function normalizeHeapProfile( + prof: AllocationProfileNode | AllocationProfileNodeWithStats, + options: HeapProfileNormalizerOptions, +): NormalizedProfile { + return collect(visitor => visitHeapProfile(prof, visitor, options)); +} diff --git a/ts/src/profile-serializer.ts b/ts/src/profile-serializer.ts index 0e5d349c..aecac7a2 100644 --- a/ts/src/profile-serializer.ts +++ b/ts/src/profile-serializer.ts @@ -21,62 +21,37 @@ import { Line, Location, Profile, + ProfileInput, Sample, ValueType, StringTable, - ProfileInput, } from 'pprof-format'; import { - GeneratedLocation, - SourceLocation, - SourceMapper, -} from './sourcemapper/sourcemapper'; + Frame, + frameFunctionName, + HeapProfileNormalizerOptions, + ProfileVisitor, + SampleLabel, + SampleType, + TimeProfileNormalizerOptions, + visitHeapProfile, + visitTimeProfile, + VisitResult, +} from './profile-normalizer'; +import {SourceMapper} from './sourcemapper/sourcemapper'; import { - Allocation, - AllocationWithStats, AllocationProfileNode, AllocationProfileNodeWithStats, GenerateAllocationLabelsFunction, GenerateTimeLabelsFunction, - ProfileNode, TimeProfile, - TimeProfileNode, } from './v8-types'; -export const NON_JS_THREADS_FUNCTION_NAME = 'Non JS threads activity'; -export const GARBAGE_COLLECTION_FUNCTION_NAME = 'Garbage Collection'; - -/** - * A stack of function IDs. - */ -type Stack = number[]; - -/** - * A function which converts entry into one or more samples, then - * appends those sample(s) to samples. - */ -type AppendEntryToSamples = ( - entry: Entry, - samples: Sample[], -) => void; - -/** - * Profile node and stack trace to that node. - */ -interface Entry { - node: T; - stack: Stack; -} - -function isGeneratedLocation( - location: SourceLocation, -): location is GeneratedLocation { - return ( - location.column !== undefined && - location.line !== undefined && - location.line > 0 - ); -} +export { + computeTotalHitCount, + GARBAGE_COLLECTION_FUNCTION_NAME, + NON_JS_THREADS_FUNCTION_NAME, +} from './profile-normalizer'; /** * Controls how a frame's column number is represented in the emitted profile. @@ -127,71 +102,66 @@ function packLineAndColumn( return (BigInt(column) << 32n) | BigInt(line); } -function requireAllocationStat( - value: number | undefined, - field: string, -): number { - if (value === undefined) { - throw new Error(`Allocation profile is missing ${field}.`); - } - return value; -} - /** - * Takes v8 profile and populates sample, location, and function fields of - * profile.proto. + * Encodes a normalized profile as a profile proto. * - * @param profile - profile.proto with empty sample, location, and function - * fields. - * @param root - root of v8 profile tree describing samples to be appended - * to profile. - * @param appendToSamples - function which converts entry to sample(s) and - * appends these to end of an array of samples. - * @param stringTable - string table for the existing profile. + * @param visit - function that delivers the normalized profile to a visitor. + * @param lowCardinalityLabels - keys of labels with few distinct values, whose + * Label objects are shared between samples to save memory. */ -function serialize( - profile: ProfileInput, - root: T, - appendToSamples: AppendEntryToSamples, - stringTable: StringTable, - ignoreSamplesPath?: string, - sourceMapper?: SourceMapper, +function serialize( + visit: (visitor: ProfileVisitor) => VisitResult, + lowCardinalityLabels: string[] = [], columnNumbers: ColumnNumbers = DEFAULT_COLUMN_NUMBERS, -) { +): Profile { + const stringTable = new StringTable(); const samples: Sample[] = []; const locations: Location[] = []; + const stacks: number[][] = []; const functions: Function[] = []; const functionIdMap = new Map(); - const locationIdMap = new Map(); const packColumns = columnNumbers === 'pack'; const emitColumns = columnNumbers === 'emit'; - - let hasMissingMapFiles = false; - - const entries: Array> = (root.children as T[]).map((n: T) => ({ - node: n, - stack: [], - })); - while (entries.length > 0) { - const entry = entries.pop()!; - const node = entry.node; - - // mjs files have a `file://` prefix in the scriptName -> remove it - const scriptName = node.scriptName.startsWith('file://') - ? node.scriptName.slice(7) - : node.scriptName; - - if (ignoreSamplesPath && scriptName.indexOf(ignoreSamplesPath) > -1) { - continue; - } - const stack = entry.stack; - const location = getLocation(node, scriptName, sourceMapper); - stack.unshift(location.id as number); - appendToSamples(entry, samples); - for (const child of node.children as T[]) { - entries.push({node: child, stack: stack.slice()}); - } + const labelCaches: Map[] = []; + for (const l of lowCardinalityLabels) { + labelCaches[stringTable.dedup(l)] = new Map(); } + let profile: ProfileInput = {}; + + const {hasMissingMapFiles} = visit({ + metadata: metadata => { + const valueType = (t: SampleType) => + new ValueType({ + type: stringTable.dedup(t.type), + unit: stringTable.dedup(t.unit), + }); + profile = { + sampleType: metadata.sampleTypes.map(valueType), + // pprof Profile objects have always had a number here; keep it one. + // It rounds the time to a double, like Date.now() * 1000 * 1000 did. + timeNanos: Number(metadata.timeNanos), + durationNanos: metadata.durationNanos, + periodType: valueType(metadata.periodType), + period: metadata.period, + }; + }, + frame: frame => { + // id is index+1, since 0 is not valid id. + const id = locations.length + 1; + locations.push(new Location({id, line: [getLine(frame)]})); + return id; + }, + stack: frameIds => stacks.push(frameIds) - 1, + sample: sample => { + samples.push( + new Sample({ + locationId: stacks[sample.stackId], + value: sample.values, + label: dedupLabels(buildLabels(sample.labels)), + }), + ); + }, + }); profile.sample = samples; profile.location = locations; @@ -202,75 +172,38 @@ function serialize( profile.comment = [stringTable.dedup('dd:has-missing-map-files')]; } - function getLocation( - node: ProfileNode, - scriptName: string, - sourceMapper?: SourceMapper, - ): Location { - let profLoc: SourceLocation = { - file: scriptName || '', - line: node.lineNumber, - column: node.columnNumber, - name: node.name, - }; - - if (profLoc.line) { - if (sourceMapper && isGeneratedLocation(profLoc)) { - profLoc = sourceMapper.mappingInfo(profLoc); - if (profLoc.missingMapFile) { - hasMissingMapFiles = true; - } - } - } - // The resolved file is part of a location's identity: after source - // mapping, one script can map to several original files. The file's - // length makes the key unambiguous. - const file = profLoc.file || ''; - const keyStr = `${node.scriptId}:${profLoc.line}:${profLoc.column}:${profLoc.missingMapFile ? 1 : 0}:${file.length}:${file}:${profLoc.name}`; - let id = locationIdMap.get(keyStr); - if (id !== undefined) { - // id is index+1, since 0 is not valid id. - return locations[id - 1]; - } - id = locations.length + 1; - locationIdMap.set(keyStr, id); - const line = getLine(profLoc, node.scriptId); - const location = new Location({id, line: [line]}); - locations.push(location); - return location; - } + return new Profile(profile); - function getLine(loc: SourceLocation, scriptId?: number): Line { + function getLine(frame: Frame): Line { // Both 'pack' and 'emit' carry the column only for frames whose source map // was declared but missing locally — i.e. exactly the frames bound for // server-side unminification (the same condition that sets // dd:has-missing-map-files). Locally-resolved frames keep a plain line and // no column, so column data never reaches profiles that skip server-side // unminification. - const carryColumn = loc.missingMapFile === true; + const carryColumn = frame.missingMapFile; return new Line({ - functionId: getFunction(loc, scriptId).id, + functionId: getFunction(frame).id, // 'pack' encodes the column into the high 32 bits of the line field. line: packColumns && carryColumn - ? packLineAndColumn(loc.line, loc.column) - : loc.line, + ? packLineAndColumn(frame.line, frame.column) + : frame.line, // 'emit' records the column in the dedicated pprof Line.column field // instead; the backend does the line/column packing itself. - column: emitColumns && carryColumn ? loc.column : undefined, + column: emitColumns && carryColumn ? frame.column : undefined, }); } - function getFunction(loc: SourceLocation, scriptId?: number): Function { - let name = loc.name; + function getFunction(frame: Frame): Function { // A function is identified by script, file and name, or by script, file // and position for anonymous functions; the prefixes keep the two kinds // apart. The file matters because after source mapping, one script can // map to several original files. - const file = loc.file || ''; - const keyStr = name - ? `n:${scriptId}:${file.length}:${file}:${name}` - : `a:${scriptId}:${loc.line}:${loc.column}:${file}`; + const file = frame.file; + const keyStr = frame.name + ? `n:${frame.scriptId}:${file.length}:${file}:${frame.name}` + : `a:${frame.scriptId}:${frame.line}:${frame.column}:${file}`; let id = functionIdMap.get(keyStr); if (id !== undefined) { // id is index+1, since 0 is not valid id. @@ -278,217 +211,33 @@ function serialize( } id = functions.length + 1; functionIdMap.set(keyStr, id); - if (!name) { - if (loc.line) { - if (loc.column) { - name = `(anonymous:L#${loc.line}:C#${loc.column})`; - } else { - name = `(anonymous:L#${loc.line})`; - } - } else { - name = '(anonymous)'; - } - } - const nameId = stringTable.dedup(name); + const nameId = stringTable.dedup(frameFunctionName(frame)); const f = new Function({ id, name: nameId, systemName: nameId, - filename: stringTable.dedup(loc.file || ''), + filename: stringTable.dedup(frame.file), }); functions.push(f); return f; } -} -/** - * @return value type for sample counts (type:sample, units:count), and - * adds strings used in this value type to the table. - */ -function createSampleCountValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('sample'), - unit: table.dedup('count'), - }); -} - -/** - * @return value type for time samples (type:wall, units:nanoseconds), and - * adds strings used in this value type to the table. - */ -function createTimeValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('wall'), - unit: table.dedup('nanoseconds'), - }); -} - -/** - * @return value type for cpu samples (type:cpu, units:nanoseconds), and - * adds strings used in this value type to the table. - */ -function createCpuValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('cpu'), - unit: table.dedup('nanoseconds'), - }); -} - -function createInUseObjectCountValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('inuse_objects'), - unit: table.dedup('count'), - }); -} - -function createAllocatedObjectCountValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('alloc_objects'), - unit: table.dedup('count'), - }); -} - -function createInUseSpaceValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('inuse_space'), - unit: table.dedup('bytes'), - }); -} - -function createAllocatedSpaceValueType(table: StringTable): ValueType { - return new ValueType({ - type: table.dedup('alloc_space'), - unit: table.dedup('bytes'), - }); -} - -export function computeTotalHitCount(root: TimeProfileNode): number { - return ( - root.hitCount + - (root.children as TimeProfileNode[]).reduce( - (sum, node) => sum + computeTotalHitCount(node), - 0, - ) - ); -} - -/** Perform some modifications on time profile: - * - Add non-JS thread activity node if available - * - remove `(program)` nodes - * - remove `(idle)` nodes with no context - * - set `(idle)` nodes' wall time to zero when they have a context - * - Convert `(garbage collector)` node to `Garbage Collection` - * - Put `non-JS thread activity` node and `Garbage Collection` under a top level `Node.js` node - * This function does not change the input profile. - */ -function updateTimeProfile(prof: TimeProfile): TimeProfile { - const newTopLevelChildren: TimeProfileNode[] = []; - - let runtimeNode: TimeProfileNode | undefined; - - function getRuntimeNode(): TimeProfileNode { - if (!runtimeNode) { - runtimeNode = { - name: 'Node.js', - scriptName: '', - scriptId: 0, - lineNumber: 0, - columnNumber: 0, - children: [], - hitCount: 0, - }; - newTopLevelChildren.push(runtimeNode); - } - return runtimeNode; - } - - for (const child of prof.topDownRoot.children as TimeProfileNode[]) { - if (child.name === '(program)') { - continue; - } - if (child.name === '(idle)' && child.contexts?.length === 0) { - continue; - } - if (child.name === '(garbage collector)') { - // Create a new node to avoid modifying the input one - const newChild: TimeProfileNode = { - ...child, - name: GARBAGE_COLLECTION_FUNCTION_NAME, - }; - getRuntimeNode().children.push(newChild); - } else { - newTopLevelChildren.push(child); + function buildLabels(sampleLabels: SampleLabel[]): Label[] { + const labels: Label[] = new Array(sampleLabels.length); + for (let i = 0; i < sampleLabels.length; i++) { + const [key, value] = sampleLabels[i]; + const labelInput: LabelInput = {key: stringTable.dedup(key)}; + if (typeof value === 'string') { + labelInput.str = stringTable.dedup(value); + } else { + labelInput.num = value; + } + labels[i] = new Label(labelInput); } + return labels; } - if (prof.hasCpuTime && prof.nonJSThreadsCpuTime) { - const node: TimeProfileNode = { - name: NON_JS_THREADS_FUNCTION_NAME, - scriptName: '', - scriptId: 0, - lineNumber: 0, - columnNumber: 0, - children: [], - hitCount: 0, // 0 because this should not be accounted for wall time - contexts: [ - { - context: {}, - timestamp: BigInt(0), - cpuTime: prof.nonJSThreadsCpuTime, - asyncId: -1, - }, - ], - }; - getRuntimeNode().children.push(node); - } - return { - ...prof, - topDownRoot: {...prof.topDownRoot, children: newTopLevelChildren}, - }; -} - -/** - * Converts v8 time profile into into a profile proto. - * (https://github.com/google/pprof/blob/master/proto/profile.proto) - * - * @param prof - profile to be converted. - * @param intervalMicros - average time (microseconds) between samples. - */ -export function serializeTimeProfile( - prof: TimeProfile, - intervalMicros: number, - sourceMapper?: SourceMapper, - recomputeSamplingInterval = false, - generateLabels?: GenerateTimeLabelsFunction, - lowCardinalityLabels: string[] = [], - columnNumbers: ColumnNumbers = DEFAULT_COLUMN_NUMBERS, -): Profile { - // If requested, recompute sampling interval from profile duration and total number of hits, - // since profile duration should be #hits x interval. - // Recomputing an average interval is more accurate, since in practice intervals between - // samples are larger than the requested sampling interval (eg. 12.5ms vs 10ms requested). - // For very short durations, computation becomes meaningless (eg. if there is only one hit), - // therefore keep intervalMicros as a lower bound and 2 * intervalMicros as upper bound. - if (recomputeSamplingInterval) { - const totalHitCount = - prof.totalHitCount ?? computeTotalHitCount(prof.topDownRoot); - if (totalHitCount > 0) { - intervalMicros = Math.min( - Math.max( - Math.floor((prof.endTime - prof.startTime) / totalHitCount), - intervalMicros, - ), - 2 * intervalMicros, - ); - } - } - const intervalNanos = intervalMicros * 1000; - const stringTable = new StringTable(); - const labelCaches: Map[] = []; - for (const l of lowCardinalityLabels) { - labelCaches[stringTable.dedup(l)] = new Map(); - } - const dedupLabels = (labels: Label[]) => { + function dedupLabels(labels: Label[]) { for (let i = 0; i < labels.length; i++) { const label = labels[i]; const cache = labelCaches[Number(label.key)]; @@ -507,112 +256,36 @@ export function serializeTimeProfile( } } return labels; - }; - - const appendTimeEntryToSamples: AppendEntryToSamples = ( - entry: Entry, - samples: Sample[], - ) => { - let unlabelledHits = entry.node.hitCount; - let unlabelledCpuTime = 0; - const isIdle = entry.node.name === '(idle)'; - for (const context of entry.node.contexts || []) { - const labels = generateLabels - ? generateLabels({node: entry.node, context}) - : (context.context ?? {}); - const labelsArr = buildLabels(labels, stringTable); - if (labelsArr.length > 0) { - // Only assign wall time if there are hits, some special nodes such as `(Non-JS threads)` - // have zero hit count (since they do not count as wall time) and should not be assigned any - // wall time. Also, `(idle)` nodes should be assigned zero wall time. - const values = - unlabelledHits > 0 ? [1, isIdle ? 0 : intervalNanos] : [0, 0]; - if (prof.hasCpuTime) { - values.push(context.cpuTime ?? 0); - } - const sample = new Sample({ - locationId: entry.stack, - value: values, - label: dedupLabels(labelsArr), - }); - samples.push(sample); - unlabelledHits--; - } else if (prof.hasCpuTime) { - unlabelledCpuTime += context.cpuTime ?? 0; - } - } - if ((!isIdle && unlabelledHits > 0) || unlabelledCpuTime > 0) { - const labels = generateLabels ? generateLabels({node: entry.node}) : {}; - const values = - unlabelledHits > 0 - ? [unlabelledHits, isIdle ? 0 : unlabelledHits * intervalNanos] - : [0, 0]; - if (prof.hasCpuTime) { - values.push(unlabelledCpuTime); - } - const sample = new Sample({ - locationId: entry.stack, - value: values, - label: buildLabels(labels, stringTable), - }); - samples.push(sample); - } - }; - - const sampleValueType = createSampleCountValueType(stringTable); - const timeValueType = createTimeValueType(stringTable); - - const sampleTypes = [sampleValueType, timeValueType]; - if (prof.hasCpuTime) { - const cpuValueType = createCpuValueType(stringTable); - sampleTypes.push(cpuValueType); } +} - const profile = { - sampleType: sampleTypes, - timeNanos: Date.now() * 1000 * 1000, - durationNanos: (prof.endTime - prof.startTime) * 1000, - periodType: timeValueType, - period: intervalNanos, - }; - - const updatedProf = updateTimeProfile(prof); - - serialize( - profile, - updatedProf.topDownRoot, - appendTimeEntryToSamples, - stringTable, - undefined, +/** + * Converts v8 time profile into into a profile proto. + * (https://github.com/google/pprof/blob/master/proto/profile.proto) + * + * @param prof - profile to be converted. + * @param intervalMicros - average time (microseconds) between samples. + */ +export function serializeTimeProfile( + prof: TimeProfile, + intervalMicros: number, + sourceMapper?: SourceMapper, + recomputeSamplingInterval = false, + generateLabels?: GenerateTimeLabelsFunction, + lowCardinalityLabels: string[] = [], + columnNumbers: ColumnNumbers = DEFAULT_COLUMN_NUMBERS, +): Profile { + const options: TimeProfileNormalizerOptions = { + intervalMicros, sourceMapper, + recomputeSamplingInterval, + generateLabels, + }; + return serialize( + visitor => visitTimeProfile(prof, visitor, options), + lowCardinalityLabels, columnNumbers, ); - - return new Profile(profile); -} - -function buildLabels(labelSet: object, stringTable: StringTable): Label[] { - const labels: Label[] = []; - - for (const [key, value] of Object.entries(labelSet)) { - const labelInput: LabelInput = { - key: stringTable.dedup(key), - }; - switch (typeof value) { - case 'string': - labelInput.str = stringTable.dedup(value); - break; - case 'number': - case 'bigint': - labelInput.num = value; - break; - default: - continue; - } - labels.push(new Label(labelInput)); - } - - return labels; } /** @@ -621,13 +294,11 @@ function buildLabels(labelSet: object, stringTable: StringTable): Label[] { * * @param prof - profile to be converted. * @param startTimeNanos - start time of profile, in nanoseconds (POSIX time). - * @param durationsNanos - duration of the profile (wall clock time) in - * nanoseconds. * @param intervalBytes - bytes allocated between samples. */ export function serializeHeapProfile( prof: AllocationProfileNode | AllocationProfileNodeWithStats, - startTimeNanos: number, + startTimeNanos: number | bigint, intervalBytes: number, ignoreSamplesPath?: string, sourceMapper?: SourceMapper, @@ -635,93 +306,17 @@ export function serializeHeapProfile( allocations = false, columnNumbers: ColumnNumbers = DEFAULT_COLUMN_NUMBERS, ): Profile { - const appendHeapEntryToSamples: AppendEntryToSamples< - AllocationProfileNode | AllocationProfileNodeWithStats - > = ( - entry: Entry, - samples: Sample[], - ) => { - if (entry.node.allocations.length > 0) { - const labels = generateLabels - ? buildLabels( - generateLabels({node: entry.node as AllocationProfileNode}), - stringTable, - ) - : []; - for (const alloc of entry.node.allocations) { - // Live heap only - if (!allocations) { - const heapAllocation = alloc as Allocation; - const sample = new Sample({ - locationId: entry.stack, - value: [ - heapAllocation.count, - heapAllocation.sizeBytes * heapAllocation.count, - ], - label: labels, - // TODO: add tag for allocation size - }); - samples.push(sample); - continue; - } - - const stats = alloc as AllocationWithStats; - const inuseObjects = requireAllocationStat( - stats.inuseObjects, - 'inuseObjects', - ); - const inuseSpaceBytes = requireAllocationStat( - stats.inuseSpaceBytes, - 'inuseSpaceBytes', - ); - const allocObjects = requireAllocationStat( - stats.allocObjects, - 'allocObjects', - ); - const allocSpaceBytes = requireAllocationStat( - stats.allocSpaceBytes, - 'allocSpaceBytes', - ); - const sample = new Sample({ - locationId: entry.stack, - value: [inuseObjects, allocObjects, inuseSpaceBytes, allocSpaceBytes], - label: labels, - // TODO: add tag for allocation size - }); - samples.push(sample); - } - } - }; - - const stringTable = new StringTable(); - const sampleTypes = allocations - ? [ - createInUseObjectCountValueType(stringTable), - createAllocatedObjectCountValueType(stringTable), - createInUseSpaceValueType(stringTable), - createAllocatedSpaceValueType(stringTable), - ] - : [ - createInUseObjectCountValueType(stringTable), - createInUseSpaceValueType(stringTable), - ]; - - const profile = { - sampleType: sampleTypes, - timeNanos: startTimeNanos, - periodType: sampleTypes[sampleTypes.length - 1], - period: intervalBytes, - }; - - serialize( - profile, - prof, - appendHeapEntryToSamples, - stringTable, + const options: HeapProfileNormalizerOptions = { + startTimeNanos: BigInt(startTimeNanos), + intervalBytes, ignoreSamplesPath, sourceMapper, + generateLabels, + allocations, + }; + return serialize( + visitor => visitHeapProfile(prof, visitor, options), + [], columnNumbers, ); - - return new Profile(profile); } diff --git a/ts/src/time-profiler.ts b/ts/src/time-profiler.ts index 294b5835..af73b11c 100644 --- a/ts/src/time-profiler.ts +++ b/ts/src/time-profiler.ts @@ -24,6 +24,11 @@ import { GARBAGE_COLLECTION_FUNCTION_NAME, NON_JS_THREADS_FUNCTION_NAME, } from './profile-serializer'; +import { + NormalizedProfile, + normalizeTimeProfile, + TimeProfileNormalizerOptions, +} from './profile-normalizer'; import {SourceMapper} from './sourcemapper/sourcemapper'; import { TimeProfiler, @@ -191,6 +196,34 @@ export function stop( ); } +/** + * Same as stop(), but returns the profile normalized into a format-neutral + * representation instead of serialized as pprof. + */ +export function stopNormalized( + restart = false, + options: Pick< + TimeProfileNormalizerOptions, + 'generateLabels' | 'samplePerContext' + > = {}, +): NormalizedProfile { + return stopAndProcess(restart, profile => + normalizeTimeProfile(profile, { + ...options, + intervalMicros: gIntervalMicros, + sourceMapper: gSourceMapper, + recomputeSamplingInterval: true, + }), + ); +} + +/** + * Same as stop(), but returns the raw V8 time profile without any processing. + */ +export function stopRaw(restart = false): TimeProfile { + return stopAndProcess(restart, profile => profile); +} + function stopAndProcess( restart: boolean, processProfile: (profile: TimeProfile) => T, diff --git a/ts/src/v8-types.ts b/ts/src/v8-types.ts index 6221326f..579f3eff 100644 --- a/ts/src/v8-types.ts +++ b/ts/src/v8-types.ts @@ -22,6 +22,12 @@ export interface TimeProfile { topDownRoot: TimeProfileNode; /** V8 timer value, in microseconds, at which profile was started. */ startTime: number; + /** + * Microseconds to add to a V8 timer value (startTime, endTime) to get + * microseconds since the UNIX epoch. The same offset converts sample + * timestamps, so the converted startTime and endTime bracket them. + */ + epochOffset?: number; hasCpuTime?: boolean; /** CPU time of non-JS threads, only reported for the main worker thread */ nonJSThreadsCpuTime?: number; diff --git a/ts/test/test-heap-profiler.ts b/ts/test/test-heap-profiler.ts index 3cbc3d19..728a99c9 100644 --- a/ts/test/test-heap-profiler.ts +++ b/ts/test/test-heap-profiler.ts @@ -123,6 +123,32 @@ describe('HeapProfiler', () => { assert.deepEqual(heapProfileWithExternal, profile); }); + it('should return a normalized profile matching the serialized one', async () => { + profileStub = sinon + .stub(v8HeapProfiler, 'getAllocationProfile') + .returns(copy(v8HeapProfile)); + memoryUsageStub = sinon.stub(process, 'memoryUsage').returns({ + external: 1024, + rss: 2048, + heapTotal: 4096, + heapUsed: 2048, + arrayBuffers: 512, + }); + const intervalBytes = 1024 * 512; + heapProfiler.start(intervalBytes, 32); + const normalized = heapProfiler.normalizedProfile(); + assert.strictEqual(normalized.period, intervalBytes); + assert.strictEqual( + normalized.samples.length, + heapProfileWithExternal.sample.length, + ); + assert.deepStrictEqual( + normalized.samples.map(s => s.values), + heapProfileWithExternal.sample.map(s => s.value), + ); + assert.ok(normalized.frames.some(f => f.name === '(external)')); + }); + it('should return a profile equal to the expected profile when including all samples', async () => { profileStub = sinon .stub(v8HeapProfiler, 'getAllocationProfile') diff --git a/ts/test/test-profile-normalizer.ts b/ts/test/test-profile-normalizer.ts new file mode 100644 index 00000000..69b03ff1 --- /dev/null +++ b/ts/test/test-profile-normalizer.ts @@ -0,0 +1,514 @@ +/* + * Copyright 2026 Datadog, Inc + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import * as sinon from 'sinon'; +import {Profile} from 'pprof-format'; + +import { + Frame, + frameFunctionName, + GARBAGE_COLLECTION_FUNCTION_NAME, + NON_JS_THREADS_FUNCTION_NAME, + NormalizedProfile, + normalizeHeapProfile, + normalizeTimeProfile, + ProfileVisitor, + visitTimeProfile, +} from '../src/profile-normalizer'; +import { + serializeHeapProfile, + serializeTimeProfile, +} from '../src/profile-serializer'; +import {SourceMapper} from '../src/sourcemapper/sourcemapper'; +import {TimeProfile, TimeProfileNode} from '../src/v8-types'; +import { + labelEncodingProfile, + v8AnonymousFunctionHeapProfile, + v8HeapProfile, + v8HeapWithPathProfile, + v8TimeProfile, +} from './profiles-for-tests'; + +const assert = require('assert'); + +/** + * Renders each sample of a normalized profile as a comparable string of its + * function names (leaf first), values and labels. + */ +function describeNormalizedSamples(prof: NormalizedProfile): string[] { + return prof.samples.map(s => + JSON.stringify({ + stack: prof.stacks[s.stackId].map(i => frameFunctionName(prof.frames[i])), + values: s.values, + labels: s.labels.map(([k, v]) => [k, String(v)]), + }), + ); +} + +/** + * Same as describeNormalizedSamples, for a pprof profile. + */ +function describePprofSamples(prof: Profile): string[] { + const strings = prof.stringTable.strings; + return prof.sample.map(s => + JSON.stringify({ + stack: s.locationId.map(id => { + const location = prof.location[Number(id) - 1]; + const fn = prof.function[Number(location.line[0].functionId) - 1]; + return strings[Number(fn.name)]; + }), + values: s.value.map(Number), + labels: s.label.map(l => [ + strings[Number(l.key)], + l.str ? strings[Number(l.str)] : String(l.num), + ]), + }), + ); +} + +function makeTimeProfile(children: TimeProfileNode[]): TimeProfile { + return { + startTime: 0, + endTime: 10 * 1000 * 1000, + hasCpuTime: true, + topDownRoot: { + name: '(root)', + scriptName: 'root', + scriptId: 0, + lineNumber: 0, + columnNumber: 0, + hitCount: 0, + children, + }, + }; +} + +function makeLeaf( + name: string, + props: Partial = {}, +): TimeProfileNode { + return { + name, + scriptName: 'script', + scriptId: 1, + lineNumber: 1, + columnNumber: 1, + hitCount: 1, + children: [], + ...props, + }; +} + +describe('profile-normalizer', () => { + let dateStub: sinon.SinonStub<[], number>; + + before(() => { + dateStub = sinon.stub(Date, 'now').returns(0); + }); + after(() => { + dateStub.restore(); + }); + + describe('normalizeTimeProfile', () => { + it('should have the same samples as the serialized pprof profile', () => { + const normalized = normalizeTimeProfile(v8TimeProfile, { + intervalMicros: 1000, + }); + const pprof = serializeTimeProfile(v8TimeProfile, 1000); + assert.deepStrictEqual( + describeNormalizedSamples(normalized), + describePprofSamples(pprof), + ); + assert.strictEqual(normalized.frames.length, pprof.location.length); + assert.strictEqual(normalized.period, pprof.period); + assert.strictEqual(normalized.durationNanos, pprof.durationNanos); + }); + + it('should give the collection time exactly, as a bigint', () => { + // 1.7e18 nanoseconds is beyond the precision of a double + dateStub.returns(1700000000123); + try { + const normalized = normalizeTimeProfile(makeTimeProfile([]), { + intervalMicros: 1000, + }); + assert.strictEqual(normalized.timeNanos, 1700000000123000000n); + // The pprof profile keeps the number it has always had + const pprof = serializeTimeProfile(makeTimeProfile([]), 1000); + assert.strictEqual(pprof.timeNanos, 1700000000123 * 1000 * 1000); + } finally { + dateStub.returns(0); + } + }); + + it('should give the start of the collection period', () => { + dateStub.returns(1700000000123); + try { + // With the native profiler's epoch offset, exactly + const prof = { + ...makeTimeProfile([]), + startTime: 5_000_000, + endTime: 15_000_000, + epochOffset: 1700000000000_000 - 5_000_000, + }; + const exact = normalizeTimeProfile(prof, {intervalMicros: 1000}); + assert.strictEqual(exact.startTimeNanos, 1700000000000_000_000n); + assert.strictEqual(exact.durationNanos, 10_000_000_000); + // Without one, estimated as the collection time minus the duration + const estimated = normalizeTimeProfile(makeTimeProfile([]), { + intervalMicros: 1000, + }); + assert.strictEqual( + estimated.startTimeNanos, + 1700000000123_000_000n - 10_000_000_000n, + ); + } finally { + dateStub.returns(0); + } + }); + + it('should describe wall and sample count types, and CPU when present', () => { + const withCpu = normalizeTimeProfile(makeTimeProfile([]), { + intervalMicros: 1000, + }); + assert.deepStrictEqual(withCpu.sampleTypes, [ + {type: 'sample', unit: 'count'}, + {type: 'wall', unit: 'nanoseconds'}, + {type: 'cpu', unit: 'nanoseconds'}, + ]); + assert.deepStrictEqual(withCpu.periodType, { + type: 'wall', + unit: 'nanoseconds', + }); + const withoutCpu = normalizeTimeProfile( + {...makeTimeProfile([]), hasCpuTime: false}, + {intervalMicros: 1000}, + ); + assert.strictEqual(withoutCpu.sampleTypes.length, 2); + }); + + it('should keep only string, number and bigint labels', () => { + const normalized = normalizeTimeProfile( + labelEncodingProfile as unknown as TimeProfile, + {intervalMicros: 1000}, + ); + assert.deepStrictEqual(normalized.samples[0].labels, [ + ['someStr', 'foo'], + ['someNum', 42], + ['someBigint', 18446744073709551557n], + ]); + }); + + it('should put synthetic runtime frames under a Node.js frame', () => { + const prof = makeTimeProfile([ + makeLeaf('(program)'), + makeLeaf('(garbage collector)'), + makeLeaf('foo'), + ]); + prof.nonJSThreadsCpuTime = 500; + const normalized = normalizeTimeProfile(prof, {intervalMicros: 1000}); + const stacks = normalized.samples.map(s => + normalized.stacks[s.stackId].map(i => + frameFunctionName(normalized.frames[i]), + ), + ); + assert.deepStrictEqual(stacks.sort(), [ + [GARBAGE_COLLECTION_FUNCTION_NAME, 'Node.js'], + [NON_JS_THREADS_FUNCTION_NAME, 'Node.js'], + ['foo'], + ]); + const nonJS = normalized.samples.find( + s => + normalized.frames[normalized.stacks[s.stackId][0]].name === + NON_JS_THREADS_FUNCTION_NAME, + )!; + assert.deepStrictEqual(nonJS.values, [0, 0, 500]); + assert.strictEqual(nonJS.timestamp, undefined); + }); + + it('should emit a sample per labelled context and give idle zero wall time', () => { + const prof = makeTimeProfile([ + makeLeaf('(idle)', { + hitCount: 2, + contexts: [ + {context: {a: 'x'}, timestamp: 1n, cpuTime: 10}, + {context: {}, timestamp: 2n, cpuTime: 20}, + ], + }), + ]); + const normalized = normalizeTimeProfile(prof, {intervalMicros: 1000}); + assert.deepStrictEqual( + normalized.samples.map(s => [s.values, s.labels, s.timestamp]), + [ + // Labelled samples carry the context timestamp in nanoseconds. + [[1, 0, 10], [['a', 'x']], 1000n], + // The unlabelled context's hit and CPU time go into one aggregated + // sample, without a timestamp. + [[1, 0, 20], [], undefined], + ], + ); + }); + + it('should emit a timestamped sample per context with samplePerContext', () => { + const prof = makeTimeProfile([ + makeLeaf('(idle)', { + hitCount: 2, + contexts: [ + {context: {a: 'x'}, timestamp: 1n, cpuTime: 10}, + {context: {}, timestamp: 2n, cpuTime: 20}, + ], + }), + makeLeaf('foo', { + scriptId: 2, + // One more hit than contexts: that one stays aggregated. + hitCount: 3, + contexts: [ + {context: {}, timestamp: 3n, cpuTime: 30}, + {context: {}, timestamp: 4n, cpuTime: 40}, + ], + }), + ]); + const describe = (p: NormalizedProfile) => + p.samples.map(s => [ + frameFunctionName(p.frames[p.stacks[s.stackId][0]]), + s.values, + s.labels, + s.timestamp, + ]); + const perContext = normalizeTimeProfile(prof, { + intervalMicros: 1000, + samplePerContext: true, + }); + assert.deepStrictEqual(describe(perContext), [ + ['foo', [1, 1000000, 30], [], 3000n], + ['foo', [1, 1000000, 40], [], 4000n], + ['foo', [1, 1000000, 0], [], undefined], + ['(idle)', [1, 0, 10], [['a', 'x']], 1000n], + ['(idle)', [1, 0, 20], [], 2000n], + ]); + // Totals match the default, aggregating mode. + const aggregated = normalizeTimeProfile(prof, {intervalMicros: 1000}); + assert.deepStrictEqual(describe(aggregated), [ + ['foo', [3, 3000000, 70], [], undefined], + ['(idle)', [1, 0, 10], [['a', 'x']], 1000n], + ['(idle)', [1, 0, 20], [], undefined], + ]); + }); + + it('should pass the context to generateLabels', () => { + const context = {context: {}, timestamp: 42n}; + const prof = makeTimeProfile([makeLeaf('foo', {contexts: [context]})]); + const generateLabels = sinon.stub().returns({ts: 42n}); + const normalized = normalizeTimeProfile(prof, { + intervalMicros: 1000, + generateLabels, + }); + sinon.assert.calledOnce(generateLabels); + assert.strictEqual(generateLabels.getCall(0).args[0].context, context); + assert.deepStrictEqual(normalized.samples[0].labels, [['ts', 42n]]); + }); + + it('should keep frames from different original files apart', () => { + // One generated script whose two positions map to different original + // files, with the same function name and position + const sourceMapper = { + mappingInfo: (loc: {line: number}) => ({ + file: loc.line === 1 ? '/app/a.ts' : '/app/b.ts', + line: 1, + column: 1, + name: 'render', + }), + } as unknown as SourceMapper; + const prof = makeTimeProfile([ + makeLeaf('x', {scriptId: 42, lineNumber: 1, columnNumber: 5}), + makeLeaf('y', {scriptId: 42, lineNumber: 2, columnNumber: 5}), + ]); + const normalized = normalizeTimeProfile(prof, { + intervalMicros: 1000, + sourceMapper, + }); + assert.deepStrictEqual(normalized.frames.map(f => f.file).sort(), [ + '/app/a.ts', + '/app/b.ts', + ]); + assert.strictEqual(normalized.stacks.length, 2); + + const pprof = serializeTimeProfile(prof, 1000, sourceMapper); + const strings = pprof.stringTable.strings; + assert.deepStrictEqual( + pprof.function.map(f => strings[Number(f.filename)]).sort(), + ['/app/a.ts', '/app/b.ts'], + ); + }); + + it('should keep named and anonymous functions apart', () => { + // A function named like an anonymous function's position + const prof = makeTimeProfile([ + makeLeaf('1:1', {lineNumber: 5, columnNumber: 5}), + makeLeaf('', {lineNumber: 1, columnNumber: 1}), + ]); + const pprof = serializeTimeProfile(prof, 1000); + const strings = pprof.stringTable.strings; + assert.deepStrictEqual( + pprof.function.map(f => strings[Number(f.name)]).sort(), + ['(anonymous:L#1:C#1)', '1:1'], + ); + }); + + it('should strip file:// prefixes from script names', () => { + const prof = makeTimeProfile([ + makeLeaf('foo', {scriptName: 'file:///app/index.mjs'}), + ]); + const normalized = normalizeTimeProfile(prof, {intervalMicros: 1000}); + assert.strictEqual(normalized.frames[0].file, '/app/index.mjs'); + }); + }); + + describe('visitTimeProfile', () => { + it('should deliver metadata first, frames and stacks once before use, and end last', () => { + const events: string[] = []; + const frameIds = new Set(); + const stackIds = new Set(); + let nextId = 100; + const visitor: ProfileVisitor = { + metadata: () => { + events.push('metadata'); + }, + frame: () => { + events.push('frame'); + const id = nextId++; + frameIds.add(id); + return id; + }, + stack: ids => { + events.push('stack'); + for (const id of ids) { + assert.ok(frameIds.has(id), `frame ${id} delivered before stack`); + } + const id = nextId++; + stackIds.add(id); + return id; + }, + sample: s => { + events.push('sample'); + assert.ok( + stackIds.has(s.stackId), + `stack ${s.stackId} delivered before sample`, + ); + }, + }; + visitor.end = result => { + events.push('end'); + assert.deepStrictEqual(result, {hasMissingMapFiles: false}); + }; + const result = visitTimeProfile(v8TimeProfile, visitor, { + intervalMicros: 1000, + }); + assert.strictEqual(events[0], 'metadata'); + assert.strictEqual(events.lastIndexOf('metadata'), 0); + assert.ok(events.includes('sample')); + assert.strictEqual(events.indexOf('end'), events.length - 1); + assert.strictEqual(result.hasMissingMapFiles, false); + }); + + it('should deliver a stack per distinct frame sequence that has samples', () => { + // Two sibling nodes resolving to the same frame share a stack, and the + // sample-less "parent" node's stack is never delivered. + const prof = makeTimeProfile([ + makeLeaf('parent', { + hitCount: 0, + children: [makeLeaf('foo', {scriptId: 2}), makeLeaf('bar')], + }), + makeLeaf('parent', { + hitCount: 0, + children: [makeLeaf('foo', {scriptId: 2})], + }), + ]); + const normalized = normalizeTimeProfile(prof, {intervalMicros: 1000}); + const stacks = normalized.stacks.map(s => + s.map(i => frameFunctionName(normalized.frames[i])), + ); + assert.deepStrictEqual(stacks.sort(), [ + ['bar', 'parent'], + ['foo', 'parent'], + ]); + assert.strictEqual(normalized.samples.length, 3); + const fooStack = normalized.stacks.findIndex( + s => normalized.frames[s[0]].name === 'foo', + ); + assert.strictEqual( + normalized.samples.filter(s => s.stackId === fooStack).length, + 2, + ); + }); + }); + + describe('normalizeHeapProfile', () => { + it('should have the same samples as the serialized pprof profile', () => { + for (const prof of [v8HeapProfile, v8AnonymousFunctionHeapProfile]) { + const normalized = normalizeHeapProfile(prof, { + startTimeNanos: 0n, + intervalBytes: 64, + }); + const pprof = serializeHeapProfile(prof, 0, 64); + assert.deepStrictEqual( + describeNormalizedSamples(normalized), + describePprofSamples(pprof), + ); + assert.deepStrictEqual(normalized.sampleTypes, [ + {type: 'inuse_objects', unit: 'count'}, + {type: 'inuse_space', unit: 'bytes'}, + ]); + } + }); + + it('should omit samples under ignoreSamplesPath', () => { + const ignored = '@google-cloud/profiler'; + const normalized = normalizeHeapProfile(v8HeapWithPathProfile, { + startTimeNanos: 0n, + intervalBytes: 64, + ignoreSamplesPath: ignored, + }); + assert.ok(normalized.frames.length > 0); + for (const frame of normalized.frames) { + assert.ok(!frame.file.includes(ignored)); + } + }); + }); + + describe('frameFunctionName', () => { + const frame = (props: Partial): Frame => ({ + file: 'f.js', + missingMapFile: false, + ...props, + }); + + it('should return the name when there is one', () => { + assert.strictEqual(frameFunctionName(frame({name: 'foo'})), 'foo'); + }); + + it('should synthesize names for anonymous functions', () => { + assert.strictEqual( + frameFunctionName(frame({name: '', line: 3, column: 5})), + '(anonymous:L#3:C#5)', + ); + assert.strictEqual( + frameFunctionName(frame({line: 3})), + '(anonymous:L#3)', + ); + assert.strictEqual(frameFunctionName(frame({})), '(anonymous)'); + }); + }); +}); diff --git a/ts/test/test-time-profiler.ts b/ts/test/test-time-profiler.ts index 112a584e..bcd56649 100644 --- a/ts/test/test-time-profiler.ts +++ b/ts/test/test-time-profiler.ts @@ -416,6 +416,36 @@ describe('Time Profiler', () => { }); }); + it('should put sample timestamps within the collection period', async function shouldBracketTimestamps() { + if (unsupportedPlatform) { + this.skip(); + } + this.timeout(3000); + + time.start({ + intervalMicros: PROFILE_OPTIONS.intervalMicros, + withContexts: true, + }); + const testStart = hrtime.bigint(); + while (hrtime.bigint() - testStart < 200_000_000n) { + time.setContext({}); + await setTimeoutPromise(1); + } + const profile = time.stopNormalized(false, {samplePerContext: true}); + const timestamps = profile.samples + .map(sample => sample.timestamp) + .filter(timestamp => timestamp !== undefined) as bigint[]; + assert.ok(timestamps.length > 0, 'has timestamped samples'); + const start = profile.startTimeNanos!; + const end = start + BigInt(Math.round(profile.durationNanos!)); + for (const timestamp of timestamps) { + assert.ok( + timestamp >= start && timestamp <= end, + `${timestamp} outside [${start}, ${end}]`, + ); + } + }); + it('should have async IDs when enabled', async function shouldCollectAsyncIDs() { if (!(collectAsyncId && ['darwin', 'linux'].includes(process.platform))) { this.skip(); @@ -536,6 +566,27 @@ describe('Time Profiler', () => { sinon.assert.calledOnce(timeProfilerStub.stop); }); + it('should return the raw profile from stopRaw', () => { + time.start({intervalMicros: PROFILE_OPTIONS.intervalMicros}); + assert.strictEqual(time.stopRaw(true), v8TimeProfile); + assert.ok(time.isStarted()); + assert.strictEqual(time.stopRaw(), v8TimeProfile); + assert.ok(!time.isStarted()); + }); + + it('should return a normalized profile matching the serialized one from stopNormalized', () => { + time.start({intervalMicros: PROFILE_OPTIONS.intervalMicros}); + const normalized = time.stopNormalized(); + assert.ok(!time.isStarted()); + assert.strictEqual(normalized.samples.length, timeProfile.sample.length); + assert.strictEqual(normalized.frames.length, timeProfile.location.length); + assert.strictEqual(normalized.period, timeProfile.period); + assert.deepStrictEqual( + normalized.samples.map(s => s.values), + timeProfile.sample.map(s => s.value), + ); + }); + it('should serialize with the source mapper still set when stopping', () => { // Regression test: stop() used to tear down the profiler state (via // handleStopNoRestart, which clears gSourceMapper) *before* serializing,