Add proper source attribution for inlined require failures / console.logs

Author: rkalis

packages/cashc/src/compiler.ts

@@ -5,6 +5,7 @@ import {
   computeBytecodeFingerprintWithConstructorArgs,
   generateSourceMap,
   generateSourceTags,
+  generateInlineRanges,
   optimiseBytecode,
   optimiseBytecodeOld,
   scriptToAsm,
@@ -141,6 +142,7 @@ function compileCode(
     traversal.consoleLogs,
     traversal.requires,
     traversal.sourceTags,
+    traversal.inlineRanges,
     constructorParamLength,
   );
 
@@ -159,6 +161,7 @@ function compileCode(
     requires: optimisationResult.requires,
     sourceTags: generateSourceTags(optimisationResult.sourceTags) || undefined,
     functions: traversal.frames.length > 0 ? traversal.frames : undefined,
+    inlineRanges: generateInlineRanges(optimisationResult.inlineRanges) || undefined,
   };
 
   const fingerprint = computeBytecodeFingerprintWithConstructorArgs(optimisationResult.script, constructorParamLength);

packages/cashc/src/generation/GenerateTargetTraversal.ts

@@ -14,6 +14,7 @@ import {
   OptimiseBytecodeResult,
   generateSourceMap,
   generateSourceTags,
+  generateInlineRanges,
   parseSourceTags,
   FullLocationData,
   DebugFrame,
@@ -72,11 +73,12 @@ import {
   compileUnaryOp,
 } from './utils.js';
 import { isNumericType } from '../utils.js';
-import { Symbol } from '../ast/SymbolTable.js';
+import { collectFunctionCalls, isRecursive, shouldInline } from './inlining.js';
 import type { InternalCompilerOptions } from '../compiler.js';
 
 interface InlineRange {
   startIp: number;
+  endIp: number;
   frame: DebugFrame;
   line: number;
 }
@@ -95,7 +97,7 @@ export default class GenerateTargetTraversal extends AstTraversal {
   private scopeDepth = 0;
   private currentFunction: FunctionDefinitionNode;
   private constructorParameterCount: number;
-  private inlineRanges: InlineRange[] = [];
+  inlineRanges: InlineRange[] = [];
 
   constructor(private compilerOptions: InternalCompilerOptions) {
     super();
@@ -261,6 +263,7 @@ export default class GenerateTargetTraversal extends AstTraversal {
       bodyTraversal.consoleLogs,
       bodyTraversal.requires,
       bodyTraversal.sourceTags,
+      bodyTraversal.inlineRanges,
       0,
     );
 
@@ -284,6 +287,7 @@ export default class GenerateTargetTraversal extends AstTraversal {
       sourceFile: node.sourceFile,
       logs: optimised.logs,
       requires: optimised.requires,
+      inlineRanges: generateInlineRanges(optimised.inlineRanges) || undefined,
     };
   }
 
@@ -748,10 +752,12 @@ export default class GenerateTargetTraversal extends AstTraversal {
     node.parameters = this.visitList(node.parameters);
 
     const startIp = this.output.length + this.constructorParameterCount;
+    const endIp = startIp + symbol.bytecode!.length - 1;
+
     this.emit(symbol.bytecode!, { location: node.location, positionHint: PositionHint.END });
 
     if (symbol.inlinedFrame) {
-      this.inlineRanges.push({ startIp, frame: symbol.inlinedFrame, line: node.location.start.line });
+      this.inlineRanges.push({ startIp, endIp, frame: symbol.inlinedFrame, line: node.location.start.line });
     }
 
     this.popFromStack(node.parameters.length);
@@ -986,71 +992,3 @@ export default class GenerateTargetTraversal extends AstTraversal {
   }
 }
 
-const shouldInline = (
-  symbol: Symbol,
-  optimisedResult: OptimiseBytecodeResult,
-  reachableCalls: FunctionCallNode[],
-  nextFunctionId: number,
-  compilerOptions: InternalCompilerOptions,
-): boolean => {
-  if (compilerOptions.disableInlining) return false;
-  if (symbol.functionId !== undefined) return false;
-
-  const callCount = reachableCalls.filter((call) => call.identifier.symbol === symbol).length;
-  return isWorthInlining(nextFunctionId, optimisedResult.script, callCount);
-};
-
-function isWorthInlining(candidateFunctionId: number, bodyScript: Script, callCount: number): boolean {
-  const bodyBytes = scriptToBytecode(bodyScript).length;
-  const idBytes = scriptToBytecode([encodeInt(BigInt(candidateFunctionId))]).length;
-
-  const bytesWhenDefined = bodyBytes + idBytes + 1 + callCount * (idBytes + 1);
-  const bytesWhenInlined = callCount * bodyBytes;
-
-  return bytesWhenInlined <= bytesWhenDefined;
-}
-
-class FunctionCallCollector extends AstTraversal {
-  functionCalls: FunctionCallNode[] = [];
-
-  visitFunctionCall(node: FunctionCallNode): Node {
-    this.functionCalls.push(node);
-    node.parameters = this.visitList(node.parameters);
-    return node;
-  }
-}
-
-function collectFunctionCalls(node: Node): FunctionCallNode[] {
-  const collector = new FunctionCallCollector();
-  collector.visit(node);
-  return collector.functionCalls;
-}
-
-// The global functions a function's body calls directly (deduplicated). A call targets a global
-// function when its resolved symbol carries a definition node — builtin functions have none.
-function calledFunctions(func: FunctionDefinitionNode): FunctionDefinitionNode[] {
-  return collectFunctionCalls(func.body)
-    .map((call) => call.identifier.symbol?.definition)
-    .filter((definition): definition is FunctionDefinitionNode => definition instanceof FunctionDefinitionNode)
-    .filter((definition, index, definitions) => definitions.indexOf(definition) === index);
-}
-
-// A function is recursive when it can transitively call itself. Recursive functions can never be
-// inlined — expanding them would never terminate — so they always keep a shared definition.
-function isRecursive(func: FunctionDefinitionNode): boolean {
-  return transitiveCalledFunctions(func).includes(func);
-}
-
-function transitiveCalledFunctions(func: FunctionDefinitionNode): FunctionDefinitionNode[] {
-  const callees: FunctionDefinitionNode[] = [];
-
-  const visit = (current: FunctionDefinitionNode): void => calledFunctions(current).forEach((callee) => {
-    if (callees.includes(callee)) return;
-    callees.push(callee);
-    visit(callee);
-  });
-
-  visit(func);
-  return callees;
-}
-

packages/cashc/src/generation/inlining.ts

@@ -0,0 +1,74 @@
+import {
+  encodeInt,
+  OptimiseBytecodeResult,
+  Script,
+  scriptToBytecode,
+} from '@cashscript/utils';
+import { FunctionCallNode, FunctionDefinitionNode, Node } from '../ast/AST.js';
+import AstTraversal from '../ast/AstTraversal.js';
+import { Symbol } from '../ast/SymbolTable.js';
+import type { InternalCompilerOptions } from '../compiler.js';
+
+export const shouldInline = (
+  symbol: Symbol,
+  optimisedResult: OptimiseBytecodeResult,
+  reachableCalls: FunctionCallNode[],
+  nextFunctionId: number,
+  compilerOptions: InternalCompilerOptions,
+): boolean => {
+  if (compilerOptions.disableInlining) return false;
+  if (symbol.functionId !== undefined) return false;
+
+  const callCount = reachableCalls.filter((call) => call.identifier.symbol === symbol).length;
+  return isWorthInlining(nextFunctionId, optimisedResult.script, callCount);
+};
+
+function isWorthInlining(candidateFunctionId: number, bodyScript: Script, callCount: number): boolean {
+  const bodyBytes = scriptToBytecode(bodyScript).length;
+  const idBytes = scriptToBytecode([encodeInt(BigInt(candidateFunctionId))]).length;
+
+  const bytesWhenDefined = bodyBytes + idBytes + 1 + callCount * (idBytes + 1);
+  const bytesWhenInlined = callCount * bodyBytes;
+
+  return bytesWhenInlined <= bytesWhenDefined;
+}
+
+class FunctionCallCollector extends AstTraversal {
+  functionCalls: FunctionCallNode[] = [];
+
+  visitFunctionCall(node: FunctionCallNode): Node {
+    this.functionCalls.push(node);
+    node.parameters = this.visitList(node.parameters);
+    return node;
+  }
+}
+
+export function collectFunctionCalls(node: Node): FunctionCallNode[] {
+  const collector = new FunctionCallCollector();
+  collector.visit(node);
+  return collector.functionCalls;
+}
+
+export function isRecursive(func: FunctionDefinitionNode): boolean {
+  return transitiveCalledFunctions(func).includes(func);
+}
+
+function transitiveCalledFunctions(func: FunctionDefinitionNode): FunctionDefinitionNode[] {
+  const callees: FunctionDefinitionNode[] = [];
+
+  const visit = (current: FunctionDefinitionNode): void => calledFunctions(current).forEach((callee) => {
+    if (callees.includes(callee)) return;
+    callees.push(callee);
+    visit(callee);
+  });
+
+  visit(func);
+  return callees;
+}
+
+function calledFunctions(func: FunctionDefinitionNode): FunctionDefinitionNode[] {
+  return collectFunctionCalls(func.body)
+    .map((call) => call.identifier.symbol?.definition)
+    .filter((definition): definition is FunctionDefinitionNode => definition instanceof FunctionDefinitionNode)
+    .filter((definition, index, definitions) => definitions.indexOf(definition) === index);
+}

packages/cashc/test/generation/fixtures.ts

@@ -1639,6 +1639,8 @@ export const fixtures: Fixture[] = [
           { ip: 5, line: 5 },
         ],
         sourceMap: '5:16:5:27:1;:::33;:37::38:0;:8::40:1',
+        // Both literal pushes were fused into the OP_1ADDs during optimisation; the ranges track them
+        inlineRanges: '1:1:ONE;2:2:ONE',
         functions: [
           {
             // The inlined constant is documented as an id-less frame; both of its literal pushes
@@ -1735,8 +1737,9 @@ export const fixtures: Fixture[] = [
           { ip: 6, line: 9 },
         ],
         // The emitted body ops (ips 1-4) and the merged require/log entries above all map to the
-        // call site; the function's own lines live on its frame below
+        // call site; the function's own lines live on its frame below, tied together by the range
         sourceMap: '9:24:9:25;:16::26:1;;;;:8::33',
+        inlineRanges: '1:4:checked',
         functions: [
           {
             // The inlined function is documented as an id-less frame carrying its compiled body

packages/cashc/test/global-definitions.test.ts

@@ -295,6 +295,7 @@ describe('Inlining and shared definitions', () => {
       requires: [expect.objectContaining({ line: 2, message: 'must be positive' })],
     }));
     expect(artifact.debug?.functions?.[0].id).toBeUndefined();
+    expect(artifact.debug?.inlineRanges).toMatch(/^\d+:\d+:assertPositive$/);
   });
 
   it('attributes debug info spliced into a defined body to the call site within that body', () => {
@@ -321,6 +322,7 @@ describe('Inlining and shared definitions', () => {
       line: 7,
       message: 'value too large',
     }));
+    expect(artifact.debug?.functions?.[0].inlineRanges).toMatch(/^\d+:\d+:assertSmall$/);
   });
 
   it('can disable inlining for callers that need the shared-definition form', () => {

packages/cashscript/src/Errors.ts

@@ -1,5 +1,5 @@
 import { Artifact, RequireStatement, sourceMapToLocationData, Type } from '@cashscript/utils';
-import { ResolvedFrame, rootFrame } from './debug-frame.js';
+import { ResolvedFrame, resolveInlineAttribution, rootFrame } from './debug-frame.js';
 
 export class TypeError extends Error {
   constructor(actual: string, expected: Type) {
@@ -161,10 +161,15 @@ export class FailedRequireError extends FailedTransactionError {
     frame?: ResolvedFrame,
   ) {
     const resolvedFrame = frame ?? rootFrame(artifact);
-    const { statement, lineNumber } = getLocationDataForFrame(resolvedFrame, failingInstructionPointer);
-    const context = formatFrameContext(resolvedFrame, artifact.contractName, lineNumber);
 
-    const baseMessage = `${resolvedFrame.sourceName}:${lineNumber} Require statement failed at input ${inputIndex} ${context}`;
+    const inline = resolveInlineAttribution(artifact, resolvedFrame, requireStatement, 'requires');
+    const attributedFrame = inline?.frame ?? resolvedFrame;
+    const attributedIp = inline?.entry.ip ?? failingInstructionPointer;
+
+    const { statement, lineNumber } = getLocationDataForFrame(attributedFrame, attributedIp);
+    const context = formatFrameContext(attributedFrame, artifact.contractName, lineNumber);
+
+    const baseMessage = `${attributedFrame.sourceName}:${lineNumber} Require statement failed at input ${inputIndex} ${context}`;
     const baseMessageWithRequireMessage = `${baseMessage} with the following message: ${requireStatement.message}`;
     const headline = `${requireStatement.message ? baseMessageWithRequireMessage : baseMessage}.`;
 

packages/cashscript/src/debug-frame.ts

@@ -1,5 +1,5 @@
 import { AuthenticationProgramStateCommon, binToHex, encodeAuthenticationInstructions } from '@bitauth/libauth';
-import { Artifact, LogEntry, RequireStatement } from '@cashscript/utils';
+import { Artifact, DebugEntry, DebugFrame, LogEntry, RequireStatement, parseInlineRanges } from '@cashscript/utils';
 
 export interface ResolvedFrame {
   sourceMap: string;
@@ -8,6 +8,7 @@ export interface ResolvedFrame {
   ipOffset: number;
   requires: readonly RequireStatement[];
   logs: readonly LogEntry[];
+  inlineRanges?: string;
   functionName?: string;
 }
 
@@ -18,6 +19,7 @@ export const rootFrame = (artifact: Artifact): ResolvedFrame => ({
   ipOffset: artifact.constructorInputs.length,
   requires: artifact.debug?.requires ?? [],
   logs: artifact.debug?.logs ?? [],
+  inlineRanges: artifact.debug?.inlineRanges,
 });
 
 export const getActiveBytecode = (step: AuthenticationProgramStateCommon): string =>
@@ -35,13 +37,73 @@ export const resolveFrame = (
 
   if (!frame) return rootFrame(artifact);
 
+  return resolveDebugFrame(artifact, frame);
+};
+
+const resolveDebugFrame = (artifact: Artifact, frame: DebugFrame): ResolvedFrame => ({
+  sourceMap: frame.sourceMap,
+  source: frame.source ?? artifact.source,
+  sourceName: frame.sourceFile ?? `${artifact.contractName}.cash`,
+  ipOffset: 0, // function bodies have no constructor-arg prefix; their ips start at 0
+  requires: frame.requires,
+  logs: frame.logs,
+  inlineRanges: frame.inlineRanges,
+  functionName: frame.sourceFile ? frame.name : undefined,
+});
+
+export interface InlineAttribution {
+  frame: ResolvedFrame; // the inlined callable, resolved like any other frame
+  entry: DebugEntry; // the callable's own entry (frame-local ip and line)
+}
+
+export const resolveInlineAttribution = (
+  artifact: Artifact,
+  containerFrame: ResolvedFrame,
+  entry: DebugEntry,
+  kind: 'requires' | 'logs',
+): InlineAttribution | undefined => {
+  const range = parseInlineRanges(containerFrame.inlineRanges ?? '')
+    .find((candidate) => entry.ip >= candidate.startIp && entry.ip <= candidate.endIp);
+  if (!range) return undefined;
+
+  const inlinedFrame = artifact.debug?.functions?.find((candidate) => candidate.name === range.frameName);
+  if (!inlinedFrame) return undefined;
+
+  const frameEntry = findMatchingFrameEntry(containerFrame[kind], inlinedFrame[kind], range, entry);
+  if (!frameEntry) return undefined;
+
+  const frame = resolveDebugFrame(artifact, inlinedFrame);
+
+  // The callable may itself contain deeper inlined callables: attribute to the innermost one
+  return resolveInlineAttribution(artifact, frame, frameEntry, kind) ?? { frame, entry: frameEntry };
+};
+
+// A log merged from an inlined callable is attributed to the callable's own source
+export const attributeLogEntry = (
+  artifact: Artifact,
+  frame: ResolvedFrame,
+  logEntry: LogEntry,
+): { logEntry: LogEntry, sourceName: string } => {
+  const inline = resolveInlineAttribution(artifact, frame, logEntry, 'logs');
+  if (!inline) return { logEntry, sourceName: frame.sourceName };
+
   return {
-    sourceMap: frame.sourceMap,
-    source: frame.source ?? artifact.source,
-    sourceName: frame.sourceFile ?? `${artifact.contractName}.cash`,
-    ipOffset: 0, // function bodies have no constructor-arg prefix; their ips start at 0
-    requires: frame.requires,
-    logs: frame.logs,
-    ...(frame.sourceFile !== undefined ? { functionName: frame.name } : {}),
+    logEntry: { ...logEntry, line: inline.entry.line },
+    sourceName: inline.frame.sourceName,
   };
 };
+
+const findMatchingFrameEntry = (
+  containerEntries: readonly DebugEntry[],
+  frameEntries: readonly DebugEntry[],
+  range: { startIp: number, endIp: number },
+  entry: DebugEntry,
+): DebugEntry | undefined => {
+  const entriesInRange = containerEntries.filter((candidate) => (
+    candidate.ip >= range.startIp && candidate.ip <= range.endIp
+  ));
+
+  const position = entriesInRange.indexOf(entry);
+  if (position === -1) return undefined;
+  return frameEntries[position];
+};