diff --git a/CHANGELOG.md b/CHANGELOG.md index 7041efda..5434ed82 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,21 +9,27 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- ๐Ÿง  **Heap analysis**: heap is no longer a single number. Every method and call path now carries three heap metrics, so you can tell a real leak from harmless allocate-then-free churn. ([#32]) + - **Net** โ€“ bytes retained (allocated minus freed); the lasting footprint. Can be negative where a path frees more than it allocates. + - **Gross** โ€“ bytes allocated, ignoring frees; allocation churn and GC pressure. + - **Peak** โ€“ highest live heap reached on the path; the number comparable to the heap governor limit. + - Shown together in the **Memory** view (total + self), and used by the Governor Avg/Peak columns and the Call Tree heap column. Method tooltips show net heap retained. + - The Timeline governor strip plots heap as it's allocated, so you can see where it spikes. - ๐Ÿ—„๏ธ **Database tab + configurable table columns**: governor-limit visibility, a SOSL table, and column views across tables. ([#162] [#298]) - ๐Ÿ“ **Governor-limit overview** (Database): SOQL, SOSL, DML and query/DML rows shown as `used / limit`, colored as they approach the limit. - ๐Ÿงฎ **Found vs Counted** (Database): each section reconciles statements found in the log against the governor-counted total, flagging queries that didn't consume the limit (e.g. custom metadata, which is free unless it selects a long text area field or runs in a Flow). - ๐Ÿ”Ž **SOSL table**: a dedicated, searchable Database table. - ๐Ÿ—‚๏ธ **Column views** (Call Tree, Analysis, Database): switch preset column sets, show/hide columns from the **Columns** button or the header right-click menu, inline **reset** to restore defaults; choices persist per view. - - ๐Ÿท๏ธ **New columns**: **Object** (queried/target SObject, with group-by) on SOQL/DML; **SOSL Count/Rows**, **Avg Self Time** and optional **Self** variants for every governor metric; **Heap Allocated** (+ Self) via the `Memory` view and Timeline strip; and a SOQL **Query Plan** view (Relative Cost, Leading Operation, SObject Type, Cardinality). + - ๐Ÿท๏ธ **New columns**: **Object** (queried/target SObject, with group-by) on SOQL/DML; **SOSL Count/Rows**, **Avg Self Time** and optional **Self** variants for every governor metric; and a SOQL **Query Plan** view (Relative Cost, Leading Operation, SObject Type, Cardinality). - ๐Ÿ”ด **Timeline exception markers**: exceptions show as red lines, with a **Throws** count in method tooltips. ([#828]) ### Changed -- โ™ป๏ธ Replaced the deprecated `webview-ui-toolkit` with [vscode-elements](https://github.com/vscode-elements/elements) for all UI controls. ([#576]). -- ๐ŸŽ›๏ธ **Modernised dropdowns**: searchable, compact controls that carry the field and value in one place (e.g. `Group: Namespace`, `Type: All`) ([#848]). - ๐Ÿ“Š **Timeline governor limits**: tooltip rows keep a stable order and always show the `used / limit` value, so figures no longer jump around as you move the pointer. ([#827]) - ๐Ÿšง **Timeline truncation markers** now end where the log recovers, so trusted sections are no longer greyed out. ([#828]) - ๐Ÿ—‚๏ธ **Call Tree + Database styling**: VS Code style tree icons, and rows indent under their group headings. ([#832]). +- ๐ŸŽ›๏ธ **Modernised dropdowns**: searchable, compact controls that carry the field and value in one place (e.g. `Group: Namespace`, `Type: All`) ([#848]). +- โ™ป๏ธ Replaced the deprecated `webview-ui-toolkit` with [vscode-elements](https://github.com/vscode-elements/elements) for all UI controls. ([#576]). ## [1.20.0] 2026-06-18 diff --git a/README.md b/README.md index d8209b2e..163f1cc7 100644 --- a/README.md +++ b/README.md @@ -85,7 +85,7 @@ The Timeline view shows a live visualization of your Salesforce Apex log executi - **โšก Fast** โ€“ Blazing-fast zoom, pan, and rendering even on massive logs (500k+ lines). - **๐Ÿ—บ๏ธ Minimap** โ€“ Bird's-eye view with skyline density overview, viewport lens, and instant teleport. -- **๐Ÿ“Š Governor Limits Strip** โ€“ At-a-glance limit usage with traffic light coloring. Expand for detailed step chart. +- **๐Ÿ“Š Governor Limits Strip** โ€“ At-a-glance limit usage with traffic light coloring, built from individual log events so every limit (heap included) updates as it's consumed, not just at cumulative snapshots. Expand for a detailed step chart. - **๐Ÿ“ Measure & Zoom** โ€“ `Shift+Drag` to measure durations, `Alt/Option+Drag` to area-zoom, precision keyboard controls. - **๐Ÿ• Wall-Clock Time** โ€“ Toggle between elapsed and real-time (HH:MM:SS.mmm) on the time axis via the toolbar clock button. @@ -99,7 +99,7 @@ Also: Frame Selection & Navigation, Dynamic Frame Labels, Adaptive Frame Detail, Explore nested method calls with performance metrics: -- **Metrics**: Self Time, Total Time, SOQL/DML/SOSL Counts + Rows, Heap, Governor Limit Avg + Peak, Thrown +- **Metrics**: Self Time, Total Time, SOQL/DML/SOSL Counts + Rows, Heap (net/gross/peak), Governor Limit Avg + Peak, Thrown - **Call Tree Views**: Use Time Order for sequence, Aggregated for repeated hot paths, Bottom-Up for caller attribution - **Column Views** โ€“ Switch preset column sets (General, Time, Governor Limits, Database, Memory), show/hide columns from the header menu, reset to defaults - **Group Bottom-Up by Namespace or Type** @@ -138,6 +138,17 @@ Highlight slow Salesforce SOQL queries, non-selective filters, and DML issues, a ![Database](https://raw.githubusercontent.com/certinia/debug-log-analyzer/main/lana/assets/1_20/database.png) +## ๐Ÿ“Š Governor Limit Tracking + +Salesforce enforces governor limits per transaction. This extension tracks them _throughout_ the log, not just as a final tally: + +- **Everywhere you look** โ€“ limit usage on the Timeline strip, per-path columns in the Call Tree (average + tightest peak), and a `used / limit` overview on the Database tab. +- **Tracked vs consumed** โ€“ reconciles what the log shows against the governor-counted total, so you can spot work that didn't count against a limit (e.g. custom metadata SOQL). +- **๐Ÿง  Heap, in depth** โ€“ heap is the tricky one, since memory gets freed as well as allocated and a single number hides what happened. Every method and call path carries three heap metrics: + - **Net** โ€“ bytes retained (allocated minus freed); the lasting footprint. + - **Gross** โ€“ bytes allocated, ignoring frees; allocation churn and GC pressure. + - **Peak** โ€“ highest live heap reached on the path; the number the heap governor actually enforces. + ## ๐Ÿ” Global Search Search across all visualizations: diff --git a/apex-log-parser/__tests__/ApexLogParser.test.ts b/apex-log-parser/__tests__/ApexLogParser.test.ts index 3f64ec12..69a89310 100644 --- a/apex-log-parser/__tests__/ApexLogParser.test.ts +++ b/apex-log-parser/__tests__/ApexLogParser.test.ts @@ -381,7 +381,7 @@ describe('parseLog tests', () => { expect(thrown?.thrownCount).toEqual({ self: 1, total: 1 }); }); - it('heapAllocated is seeded on the allocation leaf and rolled up as total on ancestors', async () => { + it('heapAllocated: leaf seeds self=total=bytes; methods get direct self + rolled-up total', async () => { const log = '09:18:22.6 (100)|EXECUTION_STARTED\n\n' + '15:20:52.222 (200)|METHOD_ENTRY|[185]|01p4J00000FpS6t|Outer.run()\n' + @@ -402,9 +402,135 @@ describe('parseLog tests', () => { const outerAlloc = outer.children.find((child) => child.type === 'HEAP_ALLOCATE'); expect(outerAlloc?.heapAllocated).toEqual({ self: 10, total: 10 }); - // Inner rolls up its own 32 bytes; Outer rolls up both (10 + 32). - expect(inner.heapAllocated).toEqual({ self: 0, total: 32 }); - expect(outer.heapAllocated).toEqual({ self: 0, total: 42 }); + // self = bytes allocated directly by the method's own body (its direct leaf allocations, + // excluding sub-methods); total = self + descendants. Inner directly allocates 32; Outer + // directly allocates 10 (Inner's 32 is not Outer's self) and totals 42. + expect(inner.heapAllocated).toEqual({ self: 32, total: 32 }); + expect(outer.heapAllocated).toEqual({ self: 10, total: 42 }); + + // All allocations are positive here, so gross mirrors net. + expect(inner.heapGross).toEqual({ self: 32, total: 32 }); + expect(outer.heapGross).toEqual({ self: 10, total: 42 }); + }); + + it('heapPeak tracks peak live heap (signed net preserved; frees do not lower the peak)', async () => { + // Stats allocates then frees 500k (net 0); Data allocates 5MB and keeps it; View + // frees the 5MB (a negative HEAP_ALLOCATE is the deallocation). Running live heap: + // 500k โ†’ 0 โ†’ 5MB โ†’ 0, so the transaction peak is 5MB, reached under Data. + const log = + '09:18:22.6 (100)|EXECUTION_STARTED\n\n' + + '15:20:52.222 (200)|METHOD_ENTRY|[185]|01pRoot|Root.run()\n' + + '15:20:52.222 (300)|METHOD_ENTRY|[186]|01pCS|Stats.compute()\n' + + '15:20:52.222 (310)|HEAP_ALLOCATE|[52]|Bytes:500000\n' + + '15:20:52.222 (320)|HEAP_ALLOCATE|[52]|Bytes:-500000\n' + + '15:20:52.222 (330)|METHOD_EXIT|[186]|01pCS|Stats.compute()\n' + + '15:20:52.222 (400)|METHOD_ENTRY|[190]|01pLD|Data.load()\n' + + '15:20:52.222 (410)|HEAP_ALLOCATE|[60]|Bytes:5000000\n' + + '15:20:52.222 (420)|METHOD_EXIT|[190]|01pLD|Data.load()\n' + + '15:20:52.222 (500)|METHOD_ENTRY|[200]|01pRD|View.render()\n' + + '15:20:52.222 (510)|HEAP_ALLOCATE|[70]|Bytes:-5000000\n' + + '15:20:52.222 (520)|METHOD_EXIT|[200]|01pRD|View.render()\n' + + '15:20:52.222 (700)|METHOD_EXIT|[185]|01pRoot|Root.run()\n' + + '09:19:13.82 (2000)|EXECUTION_FINISHED\n'; + + const apexLog = parse(log); + const root = apexLog.children[0]!.children[0]!; + const byText = (text: string) => root.children.find((child) => child.text === text)!; + const stats = byText('Stats.compute()'); + const load = byText('Data.load()'); + const render = byText('View.render()'); + + // Signed net allocation is unchanged: Data keeps +5MB, View frees -5MB, the rest net 0. + expect(load.heapAllocated.total).toBe(5000000); + expect(render.heapAllocated.total).toBe(-5000000); + expect(stats.heapAllocated.total).toBe(0); + expect(root.heapAllocated.total).toBe(0); + + // Direct/self = the method's own leaf allocations. Data directly allocates +5MB, View + // directly frees -5MB; Root only calls sub-methods (no direct heap leaves), so self = 0. + expect(load.heapAllocated.self).toBe(5000000); + expect(render.heapAllocated.self).toBe(-5000000); + expect(root.heapAllocated.self).toBe(0); + + // Gross = positive allocations only (frees ignored): Stats churned 500k (net 0), Data 5MB, + // View 0 (it only frees). Root's gross totals the churn (500k + 5MB), unlike its net (0). + expect(stats.heapGross.total).toBe(500000); + expect(load.heapGross.total).toBe(5000000); + expect(render.heapGross.total).toBe(0); + expect(root.heapGross.total).toBe(5500000); + + // Peak live heap: attributed to the allocating subtree, composes to the root, never negative. + expect(stats.heapPeak).toBe(500000); + expect(load.heapPeak).toBe(5000000); + expect(render.heapPeak).toBe(0); + expect(root.heapPeak).toBe(5000000); + + // No "Maximum heap size" line in this log, so used falls back to the computed peak. + expect(apexLog.governorLimits.heapSize.used).toBe(5000000); + }); + + it('net, gross and peak are distinct for an allocate-then-free method', async () => { + // One method allocates 5MB then frees it: net nets to 0 ("no big deal"), but gross shows + // the 5MB churn and peak shows the 5MB transiently held. + const log = + '09:18:22.6 (100)|EXECUTION_STARTED\n\n' + + '15:20:52.222 (200)|METHOD_ENTRY|[1]|01pM|M.a()\n' + + '15:20:52.222 (210)|HEAP_ALLOCATE|[1]|Bytes:5000000\n' + + '15:20:52.222 (220)|HEAP_ALLOCATE|[1]|Bytes:-5000000\n' + + '15:20:52.222 (230)|METHOD_EXIT|[1]|01pM|M.a()\n' + + '09:19:13.82 (2000)|EXECUTION_FINISHED\n'; + + const method = parse(log).children[0]!.children[0]!; + expect(method.heapAllocated.total).toBe(0); // net: allocated then freed + expect(method.heapGross.total).toBe(5000000); // churn + expect(method.heapPeak).toBe(5000000); // transiently held + }); + + it('BULK_HEAP_ALLOCATE feeds net/gross/peak the same as HEAP_ALLOCATE', async () => { + const log = + '09:18:22.6 (100)|EXECUTION_STARTED\n\n' + + '15:20:52.222 (200)|METHOD_ENTRY|[1]|01pM|M.a()\n' + + '15:20:52.222 (210)|BULK_HEAP_ALLOCATE|Bytes:1000\n' + + '15:20:52.222 (220)|METHOD_EXIT|[1]|01pM|M.a()\n' + + '09:19:13.82 (2000)|EXECUTION_FINISHED\n'; + + const method = parse(log).children[0]!.children[0]!; + expect(method.heapAllocated).toEqual({ self: 1000, total: 1000 }); + expect(method.heapGross).toEqual({ self: 1000, total: 1000 }); + expect(method.heapPeak).toBe(1000); + }); + + it('governorLimits.heapSize.used is the max of the reported peak and the computed peak', () => { + const withReported = (reportedPeak: number, allocBytes: number) => + [ + '09:18:22.6 (100)|EXECUTION_STARTED', + '15:20:52.222 (200)|METHOD_ENTRY|[1]|01pM|M.a()', + `15:20:52.222 (210)|HEAP_ALLOCATE|[1]|Bytes:${allocBytes}`, + '15:20:52.222 (220)|METHOD_EXIT|[1]|01pM|M.a()', + '12:43:02.105 (300)|LIMIT_USAGE_FOR_NS|(default)|', + ` Maximum heap size: ${reportedPeak} out of 6000000`, + '09:19:13.82 (2000)|EXECUTION_FINISHED', + ].join('\n'); + + // Reported (100) below the computed peak (5,000,000) โ†’ computed wins. + expect(parse(withReported(100, 5000000)).governorLimits.heapSize.used).toBe(5000000); + // Reported (5000) above the computed peak (100) โ†’ reported wins. + expect(parse(withReported(5000, 100)).governorLimits.heapSize.used).toBe(5000); + }); + + it('governorLimits.heapSize.used is the peak across snapshots, not the last block', () => { + // Heap falls as memory is freed, so a later LIMIT_USAGE_FOR_NS block can report a lower + // (even 0) heap than an earlier one. `used` must be the peak (500000), not the last (0). + const log = [ + '09:18:22.6 (100)|EXECUTION_STARTED', + '12:43:02.105 (200)|LIMIT_USAGE_FOR_NS|(default)|', + ' Maximum heap size: 500000 out of 6000000', + '12:43:02.105 (300)|LIMIT_USAGE_FOR_NS|(default)|', + ' Maximum heap size: 0 out of 6000000', + '09:19:13.82 (2000)|EXECUTION_FINISHED', + ].join('\n'); + + expect(parse(log).governorLimits.heapSize.used).toBe(500000); }); it('Methods should have line-numbers', async () => { @@ -1314,7 +1440,9 @@ describe('Governor Limits Parsing', () => { publishImmediateDml: { used: 5, limit: 150 }, dmlRows: { used: 118, limit: 10000 }, cpuTime: { used: 17008, limit: 10000 }, - heapSize: { used: 400, limit: 6000000 }, + // Heap is the transaction PEAK (max across namespace snapshots: max(300, 100)), not the + // sum (400) โ€” global limits aren't summed (#862). + heapSize: { used: 300, limit: 6000000 }, callouts: { used: 3, limit: 100 }, emailInvocations: { used: 6, limit: 10 }, futureCalls: { used: 4, limit: 50 }, diff --git a/apex-log-parser/src/ApexLogParser.ts b/apex-log-parser/src/ApexLogParser.ts index 9507f88c..f4772aa9 100644 --- a/apex-log-parser/src/ApexLogParser.ts +++ b/apex-log-parser/src/ApexLogParser.ts @@ -33,6 +33,8 @@ export class ApexLogParser { reasons: Set = new Set(); lastTimestamp = 0; discontinuity = false; + /** Running live heap (signed HEAP_ALLOCATE deltas) maintained in log order. */ + runningHeap = 0; namespaces = new Set(); /** Every event created during this parse, indexed by `LogEvent.eventIndex`. */ eventsById: LogEvent[] = []; @@ -123,6 +125,17 @@ export class ApexLogParser { } } + /** + * Applies a signed heap allocation to the running live-heap total (a negative `bytes` is a + * deallocation) and returns the resulting live-heap level, clamped at 0. Called by the heap + * allocation leaf events in log order; the returned value seeds their `heapPeak`, which is + * then rolled up (by max) to the enclosing methods in {@link aggregateTotals}. + */ + trackHeapAllocation(bytes: number): number { + this.runningHeap += bytes; + return Math.max(0, this.runningHeap); + } + private addGovernorLimits(apexLog: ApexLog) { const totalLimits = apexLog.governorLimits; if (totalLimits) { @@ -139,6 +152,20 @@ export class ApexLogParser { currentLimit.used += value.used; } } + + // Heap is a transaction-wide PEAK, never a per-namespace sum and never the last block + // (heap falls as memory is freed, so last-block/sum both misreport it โ€” see #862 for + // why global limits aren't summed). Take the highest heap any snapshot reported, and the + // computed peak live heap (from HEAP_ALLOCATE events โ€” more precise, and the only source + // when a log has no "Maximum heap size" line). The limit (denominator) is left as the + // per-namespace value the loop set; correcting it needs certified-pool detection (#862). + let reportedHeapPeak = 0; + for (const snapshot of apexLog.governorLimits.snapshots) { + if (snapshot.limits.heapSize.used > reportedHeapPeak) { + reportedHeapPeak = snapshot.limits.heapSize.used; + } + } + totalLimits.heapSize.used = Math.max(reportedHeapPeak, apexLog.heapPeak); } } @@ -453,6 +480,19 @@ export class ApexLogParser { parent.duration.self -= child.duration.total; parent.thrownCount.total += child.thrownCount.total; parent.heapAllocated.total += child.heapAllocated.total; + parent.heapGross.total += child.heapGross.total; + // Direct/self heap: attribute only leaf allocation children (HEAP_ALLOCATE / + // BULK_HEAP_ALLOCATE, which are not `isParent`) to the enclosing method, so + // `.self` = bytes allocated by this method's own body, excluding sub-methods. + if (!child.isParent) { + parent.heapAllocated.self += child.heapAllocated.self; + parent.heapGross.self += child.heapGross.self; + } + // Peak live heap composes by max (not sum): a parent's peak is the highest + // reached anywhere in its subtree, so root.heapPeak = the transaction peak. + if (child.heapPeak > parent.heapPeak) { + parent.heapPeak = child.heapPeak; + } } } } diff --git a/apex-log-parser/src/LogEvents.ts b/apex-log-parser/src/LogEvents.ts index c58d7524..ba0747da 100644 --- a/apex-log-parser/src/LogEvents.ts +++ b/apex-log-parser/src/LogEvents.ts @@ -247,23 +247,49 @@ export abstract class LogEvent { }; /** - * Total + self heap bytes allocated (HEAP_ALLOCATE / BULK_HEAP_ALLOCATE). + * Signed NET heap bytes (alloc โˆ’ free) for HEAP_ALLOCATE / BULK_HEAP_ALLOCATE. A negative + * `HEAP_ALLOCATE` is a deallocation, so this is signed: `+` grows the heap, `โˆ’` is net + * cleanup, `~0` is neutral ("allocated then freed โ€” no lasting footprint"). This is the + * primary "does this path retain heap" metric. It is NOT the churn volume (see + * {@link heapGross}) nor the governor-comparable peak (see {@link heapPeak}). * - * `self` is seeded on the allocation leaf node (like DML/SOQL counts), so a method's - * `heapAllocated.self` is typically 0 and `heapAllocated.total` is the sum of allocations - * in this node and its children. + * `self` is the net directly in this node's own body: seeded as `bytes` on each allocation + * leaf, and (in `aggregateTotals`) summed onto the enclosing method from its direct leaf + * children only โ€” so a method's `self` excludes allocations in sub-methods. `total` is the + * net across this node and all descendants. */ heapAllocated: SelfTotal = { /** - * The net bytes allocated directly by this node. + * The net bytes retained directly by this node (excluding sub-methods). */ self: 0, /** - * The total bytes allocated in this node and child nodes + * The total net bytes retained in this node and child nodes */ total: 0, }; + /** + * GROSS heap bytes allocated (positive HEAP_ALLOCATE only; frees ignored) โ€” the churn / GC + * pressure a path creates regardless of whether it frees. Distinct from {@link heapAllocated} + * (net) and {@link heapPeak} (max live): an allocate-then-free loop has net โ‰ˆ 0 and a small + * peak but a large gross. Same self/total aggregation as {@link heapAllocated}. + */ + heapGross: SelfTotal = { + /** Gross bytes allocated directly by this node (excluding sub-methods). */ + self: 0, + /** Total gross bytes allocated in this node and child nodes. */ + total: 0, + }; + + /** + * Peak live heap (bytes) reached while this node's subtree was executing โ€” the max of the + * running live-heap total (signed HEAP_ALLOCATE deltas) over the node's window, clamped at + * 0. Always โ‰ฅ 0 and composes (child โ‰ค parent โ‰ค root), so the root equals the transaction + * peak. This is the heap number comparable to the heap governor limit. + */ + heapPeak = 0; + /** * The line types which would legitimately end this method */ @@ -294,6 +320,17 @@ export abstract class LogEvent { } } + /** + * Seeds this heap-allocation leaf's net/gross/peak metrics from a signed byte delta + * (negative = deallocation) and advances the parser's running live-heap total. Shared + * by {@link HeapAllocateLine} and {@link BulkHeapAllocateLine}. + */ + protected seedHeapLeaf(parser: ApexLogParser, bytes: number): void { + this.heapAllocated.self = this.heapAllocated.total = bytes; + this.heapGross.self = this.heapGross.total = bytes > 0 ? bytes : 0; + this.heapPeak = parser.trackHeapAllocation(bytes); + } + private parseTimestamp(text: string): number { const start = text.indexOf('('); if (start !== -1) { @@ -533,7 +570,7 @@ export class BulkHeapAllocateLine extends LogEvent { super(parser, parts); this.text = parts[2] || ''; this.bytes = parseBytes(parts[2]); - this.heapAllocated.self = this.heapAllocated.total = this.bytes; + this.seedHeapLeaf(parser, this.bytes); } } @@ -1128,7 +1165,7 @@ export class HeapAllocateLine extends LogEvent { this.lineNumber = this.parseLineNumber(parts[2]); this.text = parts[3] || ''; this.bytes = parseBytes(parts[3]); - this.heapAllocated.self = this.heapAllocated.total = this.bytes; + this.seedHeapLeaf(parser, this.bytes); } } diff --git a/lana-docs/docs/docs/features/calltree.mdx b/lana-docs/docs/docs/features/calltree.mdx index 226b2d6b..f63262fc 100644 --- a/lana-docs/docs/docs/features/calltree.mdx +++ b/lana-docs/docs/docs/features/calltree.mdx @@ -58,10 +58,18 @@ Switch column sets from the **Columns** button in the toolbar (or the header rig 1. **Time** โ€“ call count and self/total/average time. 1. **Governor Limits** โ€“ DML/SOQL/SOSL counts + rows, throws, heap, and governor limit usage (avg + peak). 1. **Database** โ€“ DML/SOQL/SOSL counts + rows. -1. **Memory** โ€“ heap self and total. +1. **Memory** โ€“ heap net (retained), gross (churn) and peak live heap, each total + self. Show or hide individual columns from the same menu; an edited view shows a **reset** icon. Choices persist per view. +### Heap analysis + +Heap is a tricky governor limit, since memory gets freed as well as allocated and a single number hides what actually happened. Every method and call path carries three heap metrics (each with a total and self variant), shown together in the **Memory** view: + +1. **Net** โ€“ bytes retained (allocated minus freed). Can be negative where a path frees more than it allocates. +1. **Gross** - bytes allocated, ignoring frees, allocation churn and GC pressure. An allocate-then-free loop has near-zero net but large gross. +1. **Peak** โ€“ highest live heap reached while the path ran. The number comparable to the heap governor limit, so it also drives the Governor Avg/Peak columns. + ### Filtering 1. Details (events with 0 time) are hidden by default but can be shown/ hidden. @@ -76,12 +84,15 @@ Debug Only and Type filtering are available in **Time Order** and **Aggregated** SOQL and SOSL query rows are reformatted onto multiple lines and syntax highlighted, so keywords, fields and bind variables are easy to read at a glance. + src="https://raw.githubusercontent.com/certinia/debug-log-analyzer/main/lana/assets/1_20/calltree-soql-format.png" + alt="A SOQL query in the Call Tree Name column, formatted across multiple lines with syntax-highlighted keywords, fields and bind variables." + style={{ + width: '50%', + height: 'auto', + maxWidth: '400px', + }} + loading="lazy" +/> ### Keyboard Navigation diff --git a/lana-docs/docs/docs/features/timeline.mdx b/lana-docs/docs/docs/features/timeline.mdx index 8413872e..354c85a1 100644 --- a/lana-docs/docs/docs/features/timeline.mdx +++ b/lana-docs/docs/docs/features/timeline.mdx @@ -140,12 +140,15 @@ Release the mouse button to zoom the viewport to fit the selected area exactly. ## Tooltip + src="https://raw.githubusercontent.com/certinia/debug-log-analyzer/main/lana/assets/1_20/timeline-tooltip.png" + alt="Tooltip showing detailed event information including event name, description, timestamps, duration, and row counts" + style={{ + width: '50%', + height: 'auto', + maxWidth: '400px', + }} + loading="lazy" +/> Hovering over an element displays detailed information about that event. Use `J` or `Cmd/Ctrl+Click` to navigate to the frame in the Call Tree. @@ -163,12 +166,15 @@ The tooltip provides the following information: The minimap gives you instant context of your entire log. Spot hotspots at a glance, jump anywhere with a click, and always know exactly where you areโ€”all without scrolling. + src="https://raw.githubusercontent.com/certinia/debug-log-analyzer/main/lana/assets/1_20/timeline-minimap.gif" + alt="The Timeline minimap: a density skyline of the whole log with a viewport lens that pans and zooms the main timeline." + style={{ + width: '50%', + height: 'auto', + maxWidth: '400px', + }} + loading="lazy" +/> ### What the Minimap Shows @@ -226,12 +232,15 @@ When hovering over the viewport lens or dragging, a label appears showing: The Governor Limits strip displays Salesforce governor limit usage over time, positioned below the main timeline. It provides instant visual feedback on limit consumption to help identify potential limit breaches. + src="https://raw.githubusercontent.com/certinia/debug-log-analyzer/main/lana/assets/1_20/timeline-gov-strip.gif" + alt="The Governor Limits strip below the Timeline, showing limit usage over time with traffic-light coloring." + style={{ + width: '50%', + height: 'auto', + maxWidth: '400px', + }} + loading="lazy" +/> ### Display Modes diff --git a/log-viewer/src/core/utility/Util.ts b/log-viewer/src/core/utility/Util.ts index 141bf66c..4271d76c 100644 --- a/log-viewer/src/core/utility/Util.ts +++ b/log-viewer/src/core/utility/Util.ts @@ -90,6 +90,11 @@ export function formatTimeRange(startTimeNs: number, endTimeNs: number): string return `${formatDuration(startTimeNs)} โ†’ ${formatDuration(endTimeNs)}`; } +/** Integer โ†’ thousand-separated string (e.g. 1572864 โ†’ "1,572,864"), for heap/byte values. */ +export function formatInteger(value: number): string { + return Math.round(value).toLocaleString(); +} + /** * Formats milliseconds-since-midnight to `HH:MM:SS.mmm` wall-clock time string. * diff --git a/log-viewer/src/features/analysis/services/CallStackSum.ts b/log-viewer/src/features/analysis/services/CallStackSum.ts index d1103777..9ed27d88 100644 --- a/log-viewer/src/features/analysis/services/CallStackSum.ts +++ b/log-viewer/src/features/analysis/services/CallStackSum.ts @@ -13,7 +13,10 @@ import type { Metric } from '../../analysis/services/RowGrouper.js'; * Used by both AnalysisView (rows = `Metric` with `nodes`) and BottomUpTable (rows * = `BottomUpRow` with `instances`). */ -export function sumDurationTotalForRootEvents(eventGroups: Iterable): number { +export function sumTotalForRootEvents( + eventGroups: Iterable, + valueOf: (node: LogEvent) => number, +): number { const allNodes = new Set(); for (const group of eventGroups) { for (const node of group) { @@ -35,13 +38,18 @@ export function sumDurationTotalForRootEvents(eventGroups: Iterable) } if (!hasAncestor) { - total += node.duration.total; + total += valueOf(node); } } return total; } +/** {@link sumTotalForRootEvents} specialised to `duration.total` (the original behaviour). */ +export function sumDurationTotalForRootEvents(eventGroups: Iterable): number { + return sumTotalForRootEvents(eventGroups, (node) => node.duration.total); +} + /** * Tabulator `bottomCalc` adapter for AnalysisView: passes each `Metric.nodes` array * to {@link sumDurationTotalForRootEvents}. See that helper for the algorithm. diff --git a/log-viewer/src/features/analysis/services/__tests__/CallStackSum.test.ts b/log-viewer/src/features/analysis/services/__tests__/CallStackSum.test.ts index 065b06dc..e2c9dab0 100644 --- a/log-viewer/src/features/analysis/services/__tests__/CallStackSum.test.ts +++ b/log-viewer/src/features/analysis/services/__tests__/CallStackSum.test.ts @@ -4,12 +4,17 @@ import { beforeEach, describe, expect, it } from '@jest/globals'; import type { LogEvent } from 'apex-log-parser'; -import { sumDurationTotalForRootEvents, sumRootNodesOnly } from '../CallStackSum.js'; +import { + sumDurationTotalForRootEvents, + sumRootNodesOnly, + sumTotalForRootEvents, +} from '../CallStackSum.js'; import type { Metric } from '../RowGrouper.js'; type EventOptions = { text: string; total: number; + heapTotal?: number; parent?: LogEvent | null; }; @@ -24,6 +29,7 @@ function createEvent(options: EventOptions): LogEvent { namespace: 'default', timestamp: nextTimestamp++, duration: { self: 0, total: options.total }, + heapAllocated: { self: 0, total: options.heapTotal ?? 0 }, dmlRowCount: { self: 0, total: 0 }, soqlRowCount: { self: 0, total: 0 }, soslRowCount: { self: 0, total: 0 }, @@ -69,6 +75,26 @@ describe('sumDurationTotalForRootEvents', () => { }); }); +describe('sumTotalForRootEvents (generic accessor)', () => { + beforeEach(() => { + nextTimestamp = 1; + }); + + it('dedups by call stack for an arbitrary field (heap total)', () => { + // Parent heap 100 (subtree total), its leaf 100; another parent 30, its leaf 30. + // Naive sum = 260; root-only dedup = 130. Proves the BottomUp heap-total footer + // won't double-count overlapping buckets. + const parentA = createEvent({ text: 'ParentA', total: 0, heapTotal: 100 }); + const leafA = createEvent({ text: 'Leaf', total: 0, heapTotal: 100, parent: parentA }); + const parentB = createEvent({ text: 'ParentB', total: 0, heapTotal: 30 }); + const leafB = createEvent({ text: 'Leaf', total: 0, heapTotal: 30, parent: parentB }); + + expect( + sumTotalForRootEvents([[parentA], [parentB], [leafA, leafB]], (n) => n.heapAllocated.total), + ).toBe(130); + }); +}); + describe('sumRootNodesOnly (Metric adapter)', () => { beforeEach(() => { nextTimestamp = 1; diff --git a/log-viewer/src/features/call-tree/components/AggregatedTable.ts b/log-viewer/src/features/call-tree/components/AggregatedTable.ts index c3005925..0f371930 100644 --- a/log-viewer/src/features/call-tree/components/AggregatedTable.ts +++ b/log-viewer/src/features/call-tree/components/AggregatedTable.ts @@ -15,6 +15,7 @@ import { makeSumSelfTimeAllVisible } from '../utils/BottomCalcs.js'; import { commonColumnDefaults, createGovernorMetricColumns, + createSelfSumHeapFooters, headerSortElement, registerTableModules, type TableCallbacks, @@ -39,6 +40,7 @@ export function createAggregatedTable( const tableRef: { current: Tabulator | undefined } = { current: undefined }; const selfTimeBottomCalc = makeSumSelfTimeAllVisible(() => tableRef.current); + const heapFooters = createSelfSumHeapFooters(() => tableRef.current); const tableData = toAggregatedCallTree(rootMethod.children, rootMethod.governorLimits); @@ -150,7 +152,7 @@ export function createAggregatedTable( headerHozAlign: 'right', bottomCalc: 'sum', }, - ...createGovernorMetricColumns(rootMethod.governorLimits), + ...createGovernorMetricColumns(rootMethod.governorLimits, heapFooters), // Time columns sit at the far right of every call-tree table. { title: 'Total Time (ms)', diff --git a/log-viewer/src/features/call-tree/components/BottomUpTable.ts b/log-viewer/src/features/call-tree/components/BottomUpTable.ts index 1587237e..c69da3c3 100644 --- a/log-viewer/src/features/call-tree/components/BottomUpTable.ts +++ b/log-viewer/src/features/call-tree/components/BottomUpTable.ts @@ -1,7 +1,7 @@ /* * Copyright (c) 2026 Certinia Inc. All rights reserved. */ -import type { ApexLog, LogEventType } from 'apex-log-parser'; +import type { ApexLog, LogEvent, LogEventType } from 'apex-log-parser'; import { Tabulator, type Options } from 'tabulator-tables'; import { vscodeMessenger } from '../../../core/messaging/VSCodeExtensionMessenger.js'; @@ -13,7 +13,10 @@ import { GroupCalcs } from '../../../tabulator/groups/GroupCalcs.js'; import { GroupChildIndent } from '../../../tabulator/groups/GroupChildIndent.js'; import { GroupSort } from '../../../tabulator/groups/GroupSort.js'; import { VirtualVerticalRenderer } from '../../../tabulator/renderer/VirtualVerticalRenderer.js'; -import { sumDurationTotalForRootEvents } from '../../analysis/services/CallStackSum.js'; +import { + sumDurationTotalForRootEvents, + sumTotalForRootEvents, +} from '../../analysis/services/CallStackSum.js'; import { soqlGroupHeader } from '../../soql/format/groupHeader.js'; import { toBottomUpTree, type BottomUpRow } from '../utils/Aggregation.js'; import { @@ -72,6 +75,22 @@ export function createBottomUpTable( _calcParams: unknown, ): number => sumDurationTotalForRootEvents(data.map((row) => row.instances)); + // Heap totals need the same call-stack dedup as totalTime: bottom-up buckets overlap, so a + // naive sum double-counts nested allocations. Self sums plainly (self never overlaps). + const heapTotalBottomCalc = + (valueOf: (node: LogEvent) => number) => + (_values: number[], data: BottomUpRow[], _calcParams: unknown): number => + sumTotalForRootEvents( + data.map((row) => row.instances), + valueOf, + ); + const heapFooters = { + netTotal: heapTotalBottomCalc((node) => node.heapAllocated.total), + grossTotal: heapTotalBottomCalc((node) => node.heapGross.total), + netSelf: 'sum' as const, + grossSelf: 'sum' as const, + }; + const { enableClipboardAndDownload, exportFileName, ...tabulatorOptionOverrides } = options; // @ts-expect-error tabulator typings are behind runtime support for keybindings @@ -202,7 +221,7 @@ export function createBottomUpTable( headerHozAlign: 'right', bottomCalc: 'sum', }, - ...createGovernorMetricColumns(rootMethod.governorLimits), + ...createGovernorMetricColumns(rootMethod.governorLimits, heapFooters), // Time columns sit at the far right of every call-tree table. { title: 'Total Time (ms)', diff --git a/log-viewer/src/features/call-tree/components/TableShared.ts b/log-viewer/src/features/call-tree/components/TableShared.ts index 49d26d90..504896f5 100644 --- a/log-viewer/src/features/call-tree/components/TableShared.ts +++ b/log-viewer/src/features/call-tree/components/TableShared.ts @@ -4,6 +4,7 @@ import type { GovernorLimits } from 'apex-log-parser'; import { Tabulator, type ColumnDefinition, type RowComponent } from 'tabulator-tables'; +import { formatInteger } from '../../../core/utility/Util.js'; import { progressFormatter } from '../../../tabulator/format/Progress.js'; import { AnchoringPolicy } from '../../../tabulator/module/AnchoringPolicy.js'; import * as CommonModules from '../../../tabulator/module/CommonModules.js'; @@ -11,6 +12,7 @@ import { Find } from '../../../tabulator/module/Find.js'; import { RowKeyboardNavigation } from '../../../tabulator/module/RowKeyboardNavigation.js'; import { RowNavigation } from '../../../tabulator/module/RowNavigation.js'; import type { AggregatedRow, BottomUpRow } from '../utils/Aggregation.js'; +import { makeSumFieldAllVisible } from '../utils/BottomCalcs.js'; import { governorCostBreakdown, type GovernorCostRow } from '../utils/GovernorCost.js'; import type { TimeOrderRow } from '../utils/TimeOrderTree.js'; @@ -54,21 +56,6 @@ export const commonColumnDefaults = { widthShrink: 0, }; -/** Bytes โ†’ human-readable (e.g. 1536 โ†’ "1.5 KB"), for heap columns/tooltips. */ -export function formatBytes(bytes: number): string { - if (bytes < 1024) { - return `${bytes} B`; - } - const units = ['KB', 'MB', 'GB']; - let value = bytes / 1024; - let unit = 0; - while (value >= 1024 && unit < units.length - 1) { - value /= 1024; - unit++; - } - return `${value.toFixed(1)} ${units[unit]}`; -} - /** * The shared "Gov. Avg (%)" column โ€” the average governor consumption across all * governors on a call path (see {@link governorCost}), rendered as a progress @@ -98,8 +85,8 @@ export function createGovernorCostColumn(governorLimits: GovernorLimits): Column return `${total.toFixed(1)}%`; } const rows = breakdown.map((m) => { - const used = m.label === 'Heap' ? formatBytes(m.used) : `${m.used}`; - const limit = m.label === 'Heap' ? formatBytes(m.limit) : `${m.limit}`; + const used = m.label === 'Heap' ? formatInteger(m.used) : `${m.used}`; + const limit = m.label === 'Heap' ? formatInteger(m.limit) : `${m.limit}`; return `${m.label} ${used}/${limit} (${m.percent.toFixed(1)}%)`; }); return `${total.toFixed(1)}% โ€” average utilisation across all governors
${rows.join('
')}`; @@ -136,8 +123,8 @@ export function createGovernorPeakColumn(governorLimits: GovernorLimits): Column if (!top) { return `${peak.toFixed(1)}%`; } - const used = top.label === 'Heap' ? formatBytes(top.used) : `${top.used}`; - const limit = top.label === 'Heap' ? formatBytes(top.limit) : `${top.limit}`; + const used = top.label === 'Heap' ? formatInteger(top.used) : `${top.used}`; + const limit = top.label === 'Heap' ? formatInteger(top.limit) : `${top.limit}`; return `Tightest single governor: ${top.label} ${used}/${limit} (${peak.toFixed(1)}%)`; }, }; @@ -189,7 +176,34 @@ export function createGovernorColumn(opts: { * identical across all three tables; spread into each table's `columns` after * its view-specific leading columns (Name, Namespace, โ€ฆ). */ -export function createGovernorMetricColumns(governorLimits: GovernorLimits): ColumnDefinition[] { +/** Per-table footer (`bottomCalc`) for each heap column, so heap totals/self match the + * table's time-column aggregation. Peak always uses 'max'. */ +export interface HeapFooterCalcs { + netTotal: ColumnDefinition['bottomCalc']; + netSelf: ColumnDefinition['bottomCalc']; + grossTotal: ColumnDefinition['bottomCalc']; + grossSelf: ColumnDefinition['bottomCalc']; +} + +/** + * Heap footers for the top-down tables (aggregated, time-order): totals are a plain + * `'sum'` (top-level rows are the non-overlapping call-stack roots), self sums every + * visible row (self never overlaps). Bottom-up needs call-stack dedup for its totals, + * so it builds its own footers instead. + */ +export function createSelfSumHeapFooters(getTable: () => Tabulator | undefined): HeapFooterCalcs { + return { + netTotal: 'sum', + grossTotal: 'sum', + netSelf: makeSumFieldAllVisible(getTable, (row) => row.heapAllocated.self), + grossSelf: makeSumFieldAllVisible(getTable, (row) => row.heapGross.self), + }; +} + +export function createGovernorMetricColumns( + governorLimits: GovernorLimits, + heapFooters: HeapFooterCalcs, +): ColumnDefinition[] { return [ createGovernorColumn({ title: 'DML Count', @@ -281,30 +295,62 @@ export function createGovernorMetricColumns(governorLimits: GovernorLimits): Col headerHozAlign: 'right', bottomCalc: 'sum', }, - createHeapColumn(governorLimits), - createHeapColumn(governorLimits, 'heapAllocated.self', 'Heap (self)', false), + createHeapBytesColumn( + 'heapAllocated.total', + 'Heap Net (bytes)', + 'Net bytes retained on this path (alloc โˆ’ free); may be negative', + heapFooters.netTotal, + ), + createHeapBytesColumn( + 'heapAllocated.self', + 'Heap Net self (bytes)', + 'Net bytes retained directly by this node (excluding sub-methods); may be negative', + heapFooters.netSelf, + false, + ), + createHeapBytesColumn( + 'heapPeak', + 'Heap Peak (bytes)', + 'Peak live heap on this path (matches the "Maximum heap size" governor)', + 'max', + ), + createHeapBytesColumn( + 'heapGross.total', + 'Heap Alloc (bytes)', + 'Total bytes allocated on this path (ignores frees; churn)', + heapFooters.grossTotal, + false, + ), + createHeapBytesColumn( + 'heapGross.self', + 'Heap Alloc self (bytes)', + 'Bytes allocated directly by this node (excluding sub-methods; ignores frees)', + heapFooters.grossSelf, + false, + ), createGovernorCostColumn(governorLimits), createGovernorPeakColumn(governorLimits), ]; } /** - * The shared "Heap Allocated" column โ€” bytes allocated on a call path, rendered - * as a bar relative to the heap governor limit. Reused across all - * call-tree/analysis tables. Pass a `heapAllocated.self` field + `visible: false` - * for the Self variant. + * A shared plain-number heap column: every heap value (net, gross, peak โ€” total & self) + * renders identically as a thousand-separated integer in bytes (no bar, no %), so the + * columns scan uniformly. The unit lives in the title. `bottomCalc` is supplied by the + * caller so each table's footer can match its time-column aggregation (per-table sum vs + * call-stack-dedup for totals, sum-all-visible for self, 'max' for peak). */ -export function createHeapColumn( - governorLimits: GovernorLimits, - field = 'heapAllocated.total', - title = 'Heap Allocated', +export function createHeapBytesColumn( + field: string, + title: string, + headerTooltip: string, + bottomCalc: ColumnDefinition['bottomCalc'], visible?: boolean, ): ColumnDefinition { - const limit = governorLimits.heapSize.limit; - const formatterParams = { precision: 0, totalValue: limit, showPercentageText: false }; return { title, field, + headerTooltip, visible, sorter: 'number', cssClass: 'number-cell', @@ -312,14 +358,11 @@ export function createHeapColumn( minWidth: 70, hozAlign: 'right', headerHozAlign: 'right', - formatter: progressFormatter, - formatterParams, - bottomCalc: 'sum', - bottomCalcFormatter: progressFormatter, - bottomCalcFormatterParams: formatterParams, + formatter: (cell) => formatInteger((cell.getValue() ?? 0) as number), + bottomCalc, + bottomCalcFormatter: (cell) => formatInteger((cell.getValue() ?? 0) as number), tooltip(_event, cell) { - const used = (cell.getValue() ?? 0) as number; - return limit > 0 ? `${formatBytes(used)} / ${formatBytes(limit)}` : formatBytes(used); + return formatInteger((cell.getValue() ?? 0) as number); }, }; } diff --git a/log-viewer/src/features/call-tree/components/TimeOrderTable.ts b/log-viewer/src/features/call-tree/components/TimeOrderTable.ts index 4a08a49c..a37c04fb 100644 --- a/log-viewer/src/features/call-tree/components/TimeOrderTable.ts +++ b/log-viewer/src/features/call-tree/components/TimeOrderTable.ts @@ -16,6 +16,7 @@ import { createCalltreeNameFormatter } from './CalltreeNameFormatter.js'; import { commonColumnDefaults, createGovernorMetricColumns, + createSelfSumHeapFooters, headerSortElement, registerTableModules, type TableCallbacks, @@ -45,6 +46,7 @@ export function createTimeOrderTable( const tableRef: { current: Tabulator | undefined } = { current: undefined }; const selfTimeBottomCalc = makeSumSelfTimeAllVisible(() => tableRef.current); + const heapFooters = createSelfSumHeapFooters(() => tableRef.current); const table = new Tabulator(container, { data: tableData, @@ -122,7 +124,7 @@ export function createTimeOrderTable( width: 120, visible: false, }, - ...createGovernorMetricColumns(governorLimits), + ...createGovernorMetricColumns(governorLimits, heapFooters), // Time columns sit at the far right of every call-tree table. { title: 'Total Time (ms)', diff --git a/log-viewer/src/features/call-tree/utils/Aggregation.ts b/log-viewer/src/features/call-tree/utils/Aggregation.ts index 81999e4f..83567947 100644 --- a/log-viewer/src/features/call-tree/utils/Aggregation.ts +++ b/log-viewer/src/features/call-tree/utils/Aggregation.ts @@ -45,8 +45,12 @@ export interface AggregatedRow { soslRowCount: SelfTotal; /** Total + self exceptions thrown */ thrownCount: SelfTotal; - /** Total + self heap bytes allocated */ + /** Total + self signed NET heap bytes (alloc โˆ’ free; may be negative) โ€” retention */ heapAllocated: SelfTotal; + /** Total + self GROSS heap bytes allocated (frees ignored) โ€” churn */ + heapGross: SelfTotal; + /** Peak live heap (bytes) reached across this row's calls โ€” the limit-comparable value */ + heapPeak: number; /** Average governor consumption across all reported governors (0โ€“100%). */ governorCost: number; /** The single tightest governor consumed on this path (0โ€“100+%). */ @@ -103,8 +107,12 @@ export interface BottomUpRow { soslRowCount: SelfTotal; /** Total + self exceptions thrown */ thrownCount: SelfTotal; - /** Total + self heap bytes allocated */ + /** Total + self signed NET heap bytes (alloc โˆ’ free; may be negative) โ€” retention */ heapAllocated: SelfTotal; + /** Total + self GROSS heap bytes allocated (frees ignored) โ€” churn */ + heapGross: SelfTotal; + /** Peak live heap (bytes) reached across this row's calls โ€” the limit-comparable value */ + heapPeak: number; /** Average governor consumption across all reported governors (0โ€“100%). */ governorCost: number; /** The single tightest governor consumed on this path (0โ€“100+%). */ @@ -282,6 +290,10 @@ function addEventToAggregatedRowWithStack( row.thrownCount.total += event.thrownCount.total; row.heapAllocated.self += event.heapAllocated.self; row.heapAllocated.total += event.heapAllocated.total; + row.heapGross.self += event.heapGross.self; + row.heapGross.total += event.heapGross.total; + // Peak live heap aggregates by max (the worst single call), not sum. + row.heapPeak = Math.max(row.heapPeak, event.heapPeak); row.instances.push(event); } @@ -335,6 +347,7 @@ type FrameContext = { soslRowTotal: number; thrownTotal: number; heapTotal: number; + heapGrossTotal: number; }; type DfsEntry = { @@ -407,6 +420,7 @@ export function toBottomUpTree( soslRowTotal: node.soslRowCount.total, thrownTotal: node.thrownCount.total, heapTotal: node.heapAllocated.total, + heapGrossTotal: node.heapGross.total, }; if (prior) { @@ -419,6 +433,7 @@ export function toBottomUpTree( prior.soslRowTotal -= node.soslRowCount.total; prior.thrownTotal -= node.thrownCount.total; prior.heapTotal -= node.heapAllocated.total; + prior.heapGrossTotal -= node.heapGross.total; } activeByName.set(stackKey, ctx); dfs.push({ node, childIdx: 0, ctx }); @@ -438,6 +453,10 @@ export function toBottomUpTree( const soslRowSelf = node.soslRowCount.self; const thrownSelf = node.thrownCount.self; const heapSelf = node.heapAllocated.self; + const heapGrossSelf = node.heapGross.self; + // Peak live heap composes by max, so (unlike the additive totals) it needs no + // deepest-frame subtraction โ€” just max this node's peak into every chain row. + const heapPeak = node.heapPeak; const totalTime = ctx.totalTime; const dmlTotal = ctx.dmlTotal; const soqlTotal = ctx.soqlTotal; @@ -447,6 +466,7 @@ export function toBottomUpTree( const soslRowTotal = ctx.soslRowTotal; const thrownTotal = ctx.thrownTotal; const heapTotal = ctx.heapTotal; + const heapGrossTotal = ctx.heapGrossTotal; // Closure captures the hoisted locals; zero-delta guards skip no-op writes // for logs without heavy DB work. @@ -502,6 +522,15 @@ export function toBottomUpTree( if (heapTotal) { b.heapAllocated.total += heapTotal; } + if (heapGrossSelf) { + b.heapGross.self += heapGrossSelf; + } + if (heapGrossTotal) { + b.heapGross.total += heapGrossTotal; + } + if (heapPeak > b.heapPeak) { + b.heapPeak = heapPeak; + } }; const top = chainIds.length - 1; @@ -622,6 +651,8 @@ function createEmptyAggregatedRow( soslRowCount: { self: 0, total: 0 }, thrownCount: { self: 0, total: 0 }, heapAllocated: { self: 0, total: 0 }, + heapGross: { self: 0, total: 0 }, + heapPeak: 0, governorCost: 0, governorCostMax: 0, _children: null, @@ -657,6 +688,8 @@ function createEmptyBottomUpRow( soslRowCount: { self: 0, total: 0 }, thrownCount: { self: 0, total: 0 }, heapAllocated: { self: 0, total: 0 }, + heapGross: { self: 0, total: 0 }, + heapPeak: 0, governorCost: 0, governorCostMax: 0, _children: null, diff --git a/log-viewer/src/features/call-tree/utils/BottomCalcs.ts b/log-viewer/src/features/call-tree/utils/BottomCalcs.ts index cf503767..5b745061 100644 --- a/log-viewer/src/features/call-tree/utils/BottomCalcs.ts +++ b/log-viewer/src/features/call-tree/utils/BottomCalcs.ts @@ -36,7 +36,10 @@ function getRowSelfTime(row: CalltreeRowUnion): number { * collect rows through a data-only table-centric helper that applies the * active filter rules without DataTree child-row initialization side effects. */ -export function makeSumSelfTimeAllVisible(getTable: () => Tabulator | undefined) { +export function makeSumFieldAllVisible( + getTable: () => Tabulator | undefined, + valueOf: (row: CalltreeRowUnion) => number, +) { return (_values: number[], _data: CalltreeRowUnion[], _calcParams: unknown): number => { const table = getTable() as BottomCalcTable | undefined; if (!table) { @@ -48,9 +51,14 @@ export function makeSumSelfTimeAllVisible(getTable: () => Tabulator | undefined) const allVisibleRows = getFilteredDataTreeRows(table); for (const row of allVisibleRows) { - total += getRowSelfTime(row); + total += valueOf(row); } return total; }; } + +/** {@link makeSumFieldAllVisible} specialised to self-time (the original behaviour). */ +export function makeSumSelfTimeAllVisible(getTable: () => Tabulator | undefined) { + return makeSumFieldAllVisible(getTable, getRowSelfTime); +} diff --git a/log-viewer/src/features/call-tree/utils/GovernorCost.ts b/log-viewer/src/features/call-tree/utils/GovernorCost.ts index 18622a9c..d12a0bf4 100644 --- a/log-viewer/src/features/call-tree/utils/GovernorCost.ts +++ b/log-viewer/src/features/call-tree/utils/GovernorCost.ts @@ -14,7 +14,12 @@ export interface GovernorCostRow { dmlRowCount: SelfTotal; soqlRowCount: SelfTotal; soslRowCount: SelfTotal; + /** Signed net heap (alloc โˆ’ free) โ€” retention. */ heapAllocated: SelfTotal; + /** Gross heap allocated (positive allocations only) โ€” churn. */ + heapGross: SelfTotal; + /** Peak live heap (bytes) reached in this path's subtree โ€” the limit-comparable heap value. */ + heapPeak: number; /** * Average governor consumption on this path (0โ€“100%): the mean of every * governor's own `used/limit ร— 100`, across all governors that have a reported @@ -46,6 +51,11 @@ interface CostMetric { * they have no per-transaction limit to accumulate against (the 2,000-row cap * is per query) and don't count against the SOQL query-rows limit; only SOSL * *queries* is a transaction total (limited to 20). + * + * Heap uses `heapPeak` (peak live heap in the subtree), NOT `heapAllocated.total`: + * heap is the only non-monotonic governor, so its signed net allocation can be + * negative and does not compose against the limit. `heapPeak` is โ‰ฅ 0 and composes, + * so it is the value comparable to the heap limit per path. */ const COST_METRICS: CostMetric[] = [ { label: 'SOQL', used: (r) => r.soqlCount.total, limit: (l) => l.soqlQueries.limit }, @@ -53,7 +63,7 @@ const COST_METRICS: CostMetric[] = [ { label: 'SOSL', used: (r) => r.soslCount.total, limit: (l) => l.soslQueries.limit }, { label: 'SOQL Rows', used: (r) => r.soqlRowCount.total, limit: (l) => l.queryRows.limit }, { label: 'DML Rows', used: (r) => r.dmlRowCount.total, limit: (l) => l.dmlRows.limit }, - { label: 'Heap', used: (r) => r.heapAllocated.total, limit: (l) => l.heapSize.limit }, + { label: 'Heap', used: (r) => r.heapPeak, limit: (l) => l.heapSize.limit }, ]; /** diff --git a/log-viewer/src/features/call-tree/utils/TimeOrderTree.ts b/log-viewer/src/features/call-tree/utils/TimeOrderTree.ts index 6df91415..16cf23d9 100644 --- a/log-viewer/src/features/call-tree/utils/TimeOrderTree.ts +++ b/log-viewer/src/features/call-tree/utils/TimeOrderTree.ts @@ -26,6 +26,10 @@ export interface TimeOrderRow { soslRowCount: SelfTotal; thrownCount: SelfTotal; heapAllocated: SelfTotal; + /** Total + self gross heap bytes allocated (frees ignored) โ€” churn */ + heapGross: SelfTotal; + /** Peak live heap (bytes) reached in this node's subtree โ€” the limit-comparable value */ + heapPeak: number; /** Average governor consumption across all reported governors (0โ€“100%). */ governorCost: number; /** The single tightest governor consumed on this path (0โ€“100+%). */ @@ -92,6 +96,8 @@ export function toTimeOrderTree( soslRowCount: event.soslRowCount, thrownCount: event.thrownCount, heapAllocated: event.heapAllocated, + heapGross: event.heapGross, + heapPeak: event.heapPeak, governorCost: 0, governorCostMax: 0, _hasDetailsDeep: selfIsDetail || childHasDetailsDeep, diff --git a/log-viewer/src/features/call-tree/utils/__tests__/Aggregation.test.ts b/log-viewer/src/features/call-tree/utils/__tests__/Aggregation.test.ts index 9a9f3e83..e3a37e39 100644 --- a/log-viewer/src/features/call-tree/utils/__tests__/Aggregation.test.ts +++ b/log-viewer/src/features/call-tree/utils/__tests__/Aggregation.test.ts @@ -64,6 +64,8 @@ function createEvent(options: EventOptions): LogEvent { soslCount: { self: options.soslSelf ?? 0, total: options.soslTotal ?? 0 }, thrownCount: { self: options.thrown ?? 0, total: options.thrown ?? 0 }, heapAllocated: { self: options.heapSelf ?? 0, total: options.heapTotal ?? 0 }, + heapGross: { self: 0, total: 0 }, + heapPeak: 0, exitTypes: [], } as unknown as LogEvent; diff --git a/log-viewer/src/features/call-tree/utils/__tests__/GovernorCost.test.ts b/log-viewer/src/features/call-tree/utils/__tests__/GovernorCost.test.ts index e1c73190..0ef70122 100644 --- a/log-viewer/src/features/call-tree/utils/__tests__/GovernorCost.test.ts +++ b/log-viewer/src/features/call-tree/utils/__tests__/GovernorCost.test.ts @@ -32,7 +32,11 @@ function row(overrides: Partial> = {}): GovernorCostRow { soqlRowCount: st(overrides.soqlRows ?? 0), dmlRowCount: st(overrides.dmlRows ?? 0), soslRowCount: st(overrides.soslRows ?? 0), - heapAllocated: st(overrides.heap ?? 0), + // `heap` drives the Heap cost metric (which reads heapPeak); heapAllocated (net) and + // heapGross (churn) are not read by the cost and are here only to satisfy the shape. + heapAllocated: st(overrides.heapNet ?? 0), + heapGross: st(overrides.heapGross ?? 0), + heapPeak: overrides.heap ?? 0, governorCost: 0, governorCostMax: 0, }; @@ -120,6 +124,21 @@ describe('governorCostBreakdown', () => { }); }); +describe('heap uses peak-live heap, not signed net allocation', () => { + it('never produces a negative cost from a net-negative subtree', () => { + // A subtree that frees more than it allocates has a negative heapAllocated.total + // but a real (โ‰ฅ0) peak live heap. Cost must reflect the peak, never go negative. + const r = row({ heap: 3000000, heapNet: -5000000 }); + expect(governorCost(r, limits())).toBeCloseTo(50 / REPORTED_GOVERNORS, 5); // heap 50% / 6 + expect(governorCostMax(r, limits())).toBeCloseTo(50, 5); + }); + + it('scores 0 when peak heap is 0 regardless of net allocation', () => { + expect(governorCost(row({ heapNet: -5000000 }), limits())).toBe(0); + expect(governorCostMax(row({ heapNet: -5000000 }), limits())).toBe(0); + }); +}); + describe('SOSL rows', () => { it('do not contribute to governor cost โ€” they have no governor limit', () => { // SOSL rows are not governed (only SOSL queries, to 20) and do not count diff --git a/log-viewer/src/features/timeline/__tests__/tooltip.test.ts b/log-viewer/src/features/timeline/__tests__/tooltip.test.ts index 394216a0..09d94613 100644 --- a/log-viewer/src/features/timeline/__tests__/tooltip.test.ts +++ b/log-viewer/src/features/timeline/__tests__/tooltip.test.ts @@ -54,6 +54,7 @@ describe('FrameTooltipRenderer', () => { soslCount: { total: 0, self: 0 }, soslRowCount: { total: 0, self: 0 }, thrownCount: { total: 0, self: 0 }, + heapAllocated: { total: 0, self: 0 }, } as unknown as LogEvent; } @@ -305,6 +306,32 @@ describe('FrameTooltipRenderer', () => { frameTooltipRenderer.hide(); }); + it('should display a lowercase net heap row as total (self N), thousand-separated', () => { + const event = createEvent(0, 1_500_000); + event.heapAllocated = { self: 1_572_864, total: 4_000_000 }; + + frameTooltipRenderer.show(event, 100, 100); + + const tooltip = container.querySelector('#timeline-tooltip') as HTMLElement; + expect(tooltip.textContent).toContain('heap:'); + // Net subtree total (with the byte unit) and the method's own net in parens. + expect(tooltip.textContent).toContain('4,000,000 bytes (self 1,572,864)'); + + frameTooltipRenderer.hide(); + }); + + it('should not display a heap row when net heap is 0 (allocated then freed)', () => { + const event = createEvent(0, 1_500_000); + event.heapAllocated = { self: 0, total: 0 }; + + frameTooltipRenderer.show(event, 100, 100); + + const tooltip = container.querySelector('#timeline-tooltip') as HTMLElement; + expect(tooltip.textContent).not.toContain('heap:'); + + frameTooltipRenderer.hide(); + }); + it('should display event text', () => { const event = createEvent(0, 100); event.text = 'Custom event description'; @@ -670,6 +697,7 @@ describe('FrameTooltipRenderer', () => { soslCount: { total: 0, self: 0 }, soslRowCount: { total: 0, self: 0 }, thrownCount: { total: 0, self: 0 }, + heapAllocated: { total: 0, self: 0 }, } as unknown as LogEvent; frameTooltipRenderer.show(event, 100, 100); diff --git a/log-viewer/src/features/timeline/optimised/FrameTooltipRenderer.ts b/log-viewer/src/features/timeline/optimised/FrameTooltipRenderer.ts index 968028c6..6f94d88f 100644 --- a/log-viewer/src/features/timeline/optimised/FrameTooltipRenderer.ts +++ b/log-viewer/src/features/timeline/optimised/FrameTooltipRenderer.ts @@ -17,6 +17,7 @@ import { } from '../../../core/utility/Util.js'; import { formatSOQL } from '../../soql/format/formatter.js'; import type { TimelineMarker } from '../types/flamechart.types.js'; +import { formatNumber } from './rendering/tooltip-utils.js'; /** * Configuration options for tooltip behavior. @@ -375,6 +376,17 @@ export class FrameTooltipRenderer { // throw is a child leaf, so it would only ever read "(self 0)". rows.push({ label: 'Throws:', value: `${event.thrownCount.total}` }); } + + if (event.heapAllocated.total || event.heapAllocated.self) { + // Net heap retained (alloc โˆ’ free): total for the subtree, self for this method's + // own body. ~0 net (allocated then freed) shows no row. Gross/peak live in the grid. + rows.push({ + label: 'heap:', + value: `${formatNumber(event.heapAllocated.total)} bytes (self ${formatNumber( + event.heapAllocated.self, + )})`, + }); + } } const descriptionText = event.text + (event.suffix ?? ''); diff --git a/log-viewer/src/features/timeline/optimised/rendering/tooltip-utils.ts b/log-viewer/src/features/timeline/optimised/rendering/tooltip-utils.ts index 35b86bf3..08844dc4 100644 --- a/log-viewer/src/features/timeline/optimised/rendering/tooltip-utils.ts +++ b/log-viewer/src/features/timeline/optimised/rendering/tooltip-utils.ts @@ -11,6 +11,8 @@ * - HeatStripTooltipRenderer (minimap metrics) */ +import { formatInteger } from '../../../../core/utility/Util.js'; + // ============================================================================ // TRAFFIC LIGHT THRESHOLDS // ============================================================================ @@ -79,7 +81,7 @@ export const PERCENT_COLORS = { * @returns Formatted string with locale-specific thousands separators */ export function formatNumber(value: number): string { - return value.toLocaleString(); + return formatInteger(value); } /** diff --git a/log-viewer/src/tabulator/ColumnViews.ts b/log-viewer/src/tabulator/ColumnViews.ts index 445afa09..78f44e23 100644 --- a/log-viewer/src/tabulator/ColumnViews.ts +++ b/log-viewer/src/tabulator/ColumnViews.ts @@ -46,6 +46,7 @@ export const CALL_TREE_VIEWS: ColumnView[] = [ 'dmlRowCount.total', 'soqlRowCount.total', 'heapAllocated.total', + 'heapPeak', 'totalTime', 'totalSelfTime', 'duration.total', @@ -73,7 +74,7 @@ export const CALL_TREE_VIEWS: ColumnView[] = [ ...LIMIT_COUNT_TOTALS, ...LIMIT_ROW_TOTALS, 'thrownCount.total', - 'heapAllocated.total', + 'heapPeak', 'governorCost', 'governorCostMax', ], @@ -84,7 +85,15 @@ export const CALL_TREE_VIEWS: ColumnView[] = [ }, { id: 'Memory', - fields: ['namespace', 'heapAllocated.self', 'heapAllocated.total', 'governorCost'], + fields: [ + 'namespace', + 'heapAllocated.total', + 'heapAllocated.self', + 'heapGross.total', + 'heapGross.self', + 'heapPeak', + 'governorCost', + ], }, ]; diff --git a/log-viewer/src/tabulator/__tests__/ColumnViews.test.ts b/log-viewer/src/tabulator/__tests__/ColumnViews.test.ts index 3ca644ec..85ff8a34 100644 --- a/log-viewer/src/tabulator/__tests__/ColumnViews.test.ts +++ b/log-viewer/src/tabulator/__tests__/ColumnViews.test.ts @@ -60,6 +60,7 @@ const CALL_TREE_FIELDS = [ 'soqlRowCount.total', 'totalTime', 'totalSelfTime', + 'heapPeak', 'heapAllocated.total', 'governorCost', ]; @@ -92,21 +93,13 @@ describe('applyColumnView', () => { it('ignores preset fields absent from this table', () => { // Bottom-up lacks the count columns; the Governor Limits preset must not error. - const { table } = fakeTable([ - 'text', - 'type', - 'totalTime', - 'heapAllocated.total', - 'governorCost', - ]); + const { table } = fakeTable(['text', 'type', 'totalTime', 'heapPeak', 'governorCost']); applyColumnView( table, getColumnView(CALL_TREE_VIEWS, 'Governor Limits')!.fields, ALWAYS_VISIBLE, ); - expect(getVisibleFields(table).sort()).toEqual( - ['governorCost', 'heapAllocated.total', 'text'].sort(), - ); + expect(getVisibleFields(table).sort()).toEqual(['governorCost', 'heapPeak', 'text'].sort()); }); it('honours a non-default always-visible field (DB tables)', () => { @@ -191,7 +184,7 @@ describe('view sets', () => { expect(general.some((f) => f.endsWith('.self') && f !== 'duration.self')).toBe(false); }); - it('General shows Heap but omits the near-always-zero SOSL columns', () => { + it('General shows Heap (net) but omits the near-always-zero SOSL columns', () => { const general = getColumnView(CALL_TREE_VIEWS, 'General')!.fields!; expect(general).toContain('heapAllocated.total'); expect(general).not.toContain('soslCount.total'); @@ -214,10 +207,13 @@ describe('view sets', () => { } }); - it('Memory view shows heap self and total', () => { + it('Memory view shows net, gross and peak heap', () => { const memory = getColumnView(CALL_TREE_VIEWS, 'Memory')!.fields!; - expect(memory).toContain('heapAllocated.self'); expect(memory).toContain('heapAllocated.total'); + expect(memory).toContain('heapAllocated.self'); + expect(memory).toContain('heapGross.total'); + expect(memory).toContain('heapGross.self'); + expect(memory).toContain('heapPeak'); }); it('SOQL Query Plan view exposes the explain-plan columns', () => {