Skip to content

Commit 6fa4c07

Browse files
rkalisrkalis
committed
Rework console.log handling for loops + add tests
1 parent cd82956 commit 6fa4c07

3 files changed

Lines changed: 119 additions & 18 deletions

File tree

‎packages/cashscript/src/debugging.ts‎

Lines changed: 40 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import { AuthenticationErrorCommon, AuthenticationInstruction, AuthenticationProgramCommon, AuthenticationProgramStateCommon, AuthenticationVirtualMachine, ResolvedTransactionCommon, WalletTemplate, WalletTemplateScriptUnlocking, binToHex, createCompiler, createVirtualMachineBch2023, createVirtualMachineBch2025, createVirtualMachineBch2026, createVirtualMachineBchSpec, decodeAuthenticationInstructions, encodeAuthenticationInstruction, walletTemplateToCompilerConfiguration } from '@bitauth/libauth';
2-
import { Artifact, LogEntry, Op, PrimitiveType, StackItem, asmToBytecode, bytecodeToAsm, decodeBool, decodeInt, decodeString } from '@cashscript/utils';
2+
import { Artifact, LogData, LogEntry, Op, PrimitiveType, StackItem, asmToBytecode, bytecodeToAsm, decodeBool, decodeInt, decodeString } from '@cashscript/utils';
33
import { findLastIndex, toRegExp } from './utils.js';
44
import { FailedRequireError, FailedTransactionError, FailedTransactionEvaluationError } from './Errors.js';
55
import { getBitauthUri } from './libauth-template/LibauthTemplate.js';
@@ -84,12 +84,26 @@ const debugSingleScenario = (
8484

8585
// P2PKH inputs do not have an artifact, so we skip the console.log handling
8686
if (artifact) {
87-
const executedLogs = (artifact.debug?.logs ?? [])
88-
.filter((log) => executedDebugSteps.some((debugStep) => log.ip === debugStep.ip));
89-
90-
for (const log of executedLogs) {
87+
// Try to match each executed debug step to a log entry if it exists. Note that inside loops,
88+
// the same log statement may be executed multiple times in different debug steps
89+
// Also note that multiple log statements may exist for the same ip, so we need to handle all of them
90+
const executedLogs = executedDebugSteps
91+
.flatMap((debugStep, index) => {
92+
const logEntries = artifact.debug?.logs?.filter((log) => log.ip === debugStep.ip);
93+
if (!logEntries || logEntries.length === 0) return [];
94+
95+
const reversedPriorDebugSteps = executedDebugSteps.slice(0, index + 1).reverse();
96+
97+
return logEntries.map((logEntry) => {
98+
const decodedLogData = logEntry.data
99+
.map((dataEntry) => decodeLogDataEntry(dataEntry, reversedPriorDebugSteps, vm));
100+
return { logEntry, decodedLogData };
101+
});
102+
});
103+
104+
for (const { logEntry, decodedLogData } of executedLogs) {
91105
const inputIndex = extractInputIndexFromScenario(scenarioId);
92-
logConsoleLogStatement(log, executedDebugSteps, artifact, inputIndex, vm);
106+
logConsoleLogStatement(logEntry, decodedLogData, artifact.contractName, inputIndex);
93107
}
94108
}
95109

@@ -221,20 +235,28 @@ const createProgram = (template: WalletTemplate, unlockingScriptId: string, scen
221235

222236
const logConsoleLogStatement = (
223237
log: LogEntry,
224-
debugSteps: AuthenticationProgramStateCommon[],
225-
artifact: Artifact,
238+
decodedLogData: Array<string | bigint | boolean>,
239+
contractName: string,
226240
inputIndex: number,
227-
vm: VM,
228241
): void => {
229-
let line = `${artifact.contractName}.cash:${log.line}`;
230-
const decodedData = log.data.map((element) => {
231-
if (typeof element === 'string') return element;
242+
console.log(`[Input #${inputIndex}] ${contractName}.cash:${log.line} ${decodedLogData.join(' ')}`);
243+
};
232244

233-
const debugStep = debugSteps.find((step) => step.ip === element.ip)!;
234-
const transformedDebugStep = applyStackItemTransformations(element, debugStep, vm);
235-
return decodeStackItem(element, transformedDebugStep.stack);
236-
});
237-
console.log(`[Input #${inputIndex}] ${line} ${decodedData.join(' ')}`);
245+
const decodeLogDataEntry = (
246+
dataEntry: LogData,
247+
reversedPriorDebugSteps: AuthenticationProgramStateCommon[],
248+
vm: VM,
249+
): string | bigint | boolean => {
250+
if (typeof dataEntry === 'string') return dataEntry;
251+
252+
const dataEntryDebugStep = reversedPriorDebugSteps.find((step) => step.ip === dataEntry.ip);
253+
254+
if (!dataEntryDebugStep) {
255+
throw new Error(`Should not happen: corresponding data entry debug step not found for entry at ip ${dataEntry.ip}`);
256+
}
257+
258+
const transformedDebugStep = applyStackItemTransformations(dataEntry, dataEntryDebugStep, vm);
259+
return decodeStackItem(dataEntry, transformedDebugStep.stack);
238260
};
239261

240262
const applyStackItemTransformations = (
@@ -267,7 +289,7 @@ const applyStackItemTransformations = (
267289
return transformationsEndState;
268290
};
269291

270-
const decodeStackItem = (element: StackItem, stack: Uint8Array[]): any => {
292+
const decodeStackItem = (element: StackItem, stack: Uint8Array[]): string | bigint | boolean => {
271293
// Reversed since stack is in reverse order
272294
const stackItem = [...stack].reverse()[element.stackIndex];
273295

‎packages/cashscript/test/debugging.test.ts‎

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,16 +13,22 @@ import {
1313
artifactTestMultilineRequires,
1414
artifactTestZeroHandling,
1515
artifactTestRequireInsideLoop,
16+
artifactTestLogInsideLoop,
1617
} from './fixture/debugging/debugging_contracts.js';
1718
import { sha256 } from '@cashscript/utils';
1819

1920
describe('Debugging tests', () => {
2021
describe('console.log statements', () => {
2122
const provider = new MockNetworkProvider();
23+
2224
const contractTestLogs = new Contract(artifactTestLogs, [alicePub], { provider });
2325
const contractUtxo = randomUtxo();
2426
provider.addUtxo(contractTestLogs.address, contractUtxo);
2527

28+
const contractTestLogInsideLoop = new Contract(artifactTestLogInsideLoop, [], { provider });
29+
const contractTestLogInsideLoopUtxo = randomUtxo();
30+
provider.addUtxo(contractTestLogInsideLoop.address, contractTestLogInsideLoopUtxo);
31+
2632
it('should log correct values', async () => {
2733
const transaction = new TransactionBuilder({ provider })
2834
.addInput(contractUtxo, contractTestLogs.unlock.transfer(new SignatureTemplate(alicePriv), 1000n))
@@ -155,6 +161,38 @@ describe('Debugging tests', () => {
155161
});
156162

157163
it.todo('intermediate results that is more complex than the test above');
164+
165+
it('should log inside a loop', async () => {
166+
const transaction = new TransactionBuilder({ provider })
167+
.addInput(contractUtxo, contractTestLogs.unlock.test_log_inside_loop())
168+
.addOutput({ to: contractTestLogs.address, amount: 10000n });
169+
170+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 0$'));
171+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 1$'));
172+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 2$'));
173+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 3$'));
174+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 4$'));
175+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 5$'));
176+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 6$'));
177+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 7$'));
178+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 8$'));
179+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:62 i: 9$'));
180+
});
181+
182+
it('should log inside a complex nested loop', async () => {
183+
const transaction = new TransactionBuilder({ provider })
184+
.addInput(contractTestLogInsideLoopUtxo, contractTestLogInsideLoop.unlock.test_log_inside_loop_complex())
185+
.addOutput({ to: contractTestLogInsideLoop.address, amount: 10000n });
186+
187+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:28 inner loop i: 0 j: 0 k: 0 l: 5 m: 10$'));
188+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:28 inner loop i: 0 j: 1 k: 1 l: 5 m: 10$'));
189+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:32 outer loop i: 0$'));
190+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:28 inner loop i: 1 j: 0 k: 1 l: 5 m: 10$'));
191+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:28 inner loop i: 1 j: 1 k: 2 l: 5 m: 10$'));
192+
expect(transaction).toLog(new RegExp('^\\[Input #0] Test.cash:32 outer loop i: 1$'));
193+
});
194+
195+
it.todo('should log intermediate results that get optimsed out inside a loop');
158196
});
159197

160198
describe('require statements', () => {

‎packages/cashscript/test/fixture/debugging/debugging_contracts.ts‎

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -264,6 +264,46 @@ contract Test(pubkey owner) {
264264
require(tx.outputs[this.activeInputIndex].value == inputValue - 1000);
265265
}
266266
}
267+
`;
268+
269+
const CONTRACT_TEST_LOG_INSIDE_LOOP = `
270+
contract Test() {
271+
function test_log_inside_loop() {
272+
int x = 0;
273+
do {
274+
console.log('x:', x);
275+
x = x + 1;
276+
} while (x < 10);
277+
278+
require(x == 10);
279+
}
280+
281+
function test_log_inside_loop_complex() {
282+
int i = 0;
283+
284+
int l = 5;
285+
require(l < 10);
286+
287+
do {
288+
int j = 0;
289+
290+
int m = 10;
291+
require(m < 20);
292+
293+
do {
294+
int k = i + j;
295+
require(k < 100);
296+
console.log('inner loop', 'i:', i, 'j:', j, 'k:', k, 'l:', l, 'm:', m);
297+
j = j + 1;
298+
} while (j < 2);
299+
300+
console.log('outer loop', 'i:', i);
301+
302+
i = i + 1;
303+
} while (i < 2);
304+
305+
require(i == 2);
306+
}
267307
}
268308
`;
269309

@@ -334,3 +374,4 @@ export const artifactTestConsecutiveLogs = compileString(CONTRACT_TEST_CONSECUTI
334374
export const artifactTestMultipleLogs = compileString(CONTRACT_TEST_MULTIPLE_LOGS);
335375
export const artifactTestMultipleConstructorParameters = compileString(CONTRACT_TEST_MULTIPLE_CONSTRUCTOR_PARAMETERS);
336376
export const artifactTestRequireInsideLoop = compileString(CONTRACT_TEST_REQUIRE_INSIDE_LOOP);
377+
export const artifactTestLogInsideLoop = compileString(CONTRACT_TEST_LOG_INSIDE_LOOP);

0 commit comments

Comments
 (0)