From ae8a7f63208094ca949563fb7f4d9b509ae66bf6 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 10:50:14 -0800 Subject: [PATCH 1/8] Remove ganache profiling warning --- contracts/test-utils/src/web3_wrapper.ts | 6 ------ 1 file changed, 6 deletions(-) diff --git a/contracts/test-utils/src/web3_wrapper.ts b/contracts/test-utils/src/web3_wrapper.ts index cb33476f3a..32432a2f2e 100644 --- a/contracts/test-utils/src/web3_wrapper.ts +++ b/contracts/test-utils/src/web3_wrapper.ts @@ -64,12 +64,6 @@ if (isCoverageEnabled) { prependSubprovider(provider, coverageSubprovider); } if (isProfilerEnabled) { - if (testProvider === ProviderType.Ganache) { - logUtils.warn( - "Gas costs in Ganache traces are incorrect and we don't recommend using it for profiling. Please switch to Geth", - ); - process.exit(1); - } const profilerSubprovider = profiler.getProfilerSubproviderSingleton(); logUtils.log( "By default profilerSubprovider is stopped so that you don't get noise from setup code. Don't forget to start it before the code you want to profile and stop it afterwards", From 462a61da73f43a1f2c9d47435acefa5f6f521a70 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 10:53:36 -0800 Subject: [PATCH 2/8] Move structLogs normalization right after we fetch the trace --- packages/sol-profiler/src/profiler_subprovider.ts | 1 - packages/sol-tracing-utils/src/revert_trace.ts | 13 ++++++------- packages/sol-tracing-utils/src/trace.ts | 11 +++++------ .../sol-tracing-utils/src/trace_info_subprovider.ts | 2 ++ 4 files changed, 13 insertions(+), 14 deletions(-) diff --git a/packages/sol-profiler/src/profiler_subprovider.ts b/packages/sol-profiler/src/profiler_subprovider.ts index 050512cbd5..85c2bb7458 100644 --- a/packages/sol-profiler/src/profiler_subprovider.ts +++ b/packages/sol-profiler/src/profiler_subprovider.ts @@ -57,7 +57,6 @@ export class ProfilerSubprovider extends TraceInfoSubprovider { return; } logUtils.header(`Profiling data for ${traceInfo.txHash}`); - traceInfo.trace.structLogs = utils.normalizeStructLogs(traceInfo.trace.structLogs); const callDataCost = costUtils.reportCallDataCost(traceInfo); const memoryCost = costUtils.reportMemoryCost(traceInfo); const opcodesCost = costUtils.reportOpcodesCost(traceInfo); diff --git a/packages/sol-tracing-utils/src/revert_trace.ts b/packages/sol-tracing-utils/src/revert_trace.ts index 4d474120ca..b40bca41d3 100644 --- a/packages/sol-tracing-utils/src/revert_trace.ts +++ b/packages/sol-tracing-utils/src/revert_trace.ts @@ -17,10 +17,9 @@ export function getRevertTrace(structLogs: StructLog[], startAddress: string): E if (_.isEmpty(structLogs)) { return []; } - const normalizedStructLogs = utils.normalizeStructLogs(structLogs); // tslint:disable-next-line:prefer-for-of - for (let i = 0; i < normalizedStructLogs.length; i++) { - const structLog = normalizedStructLogs[i]; + for (let i = 0; i < structLogs.length; i++) { + const structLog = structLogs[i]; if (structLog.depth !== addressStack.length - 1) { throw new Error("Malformed trace. Trace depth doesn't match call stack depth"); } @@ -38,7 +37,7 @@ export function getRevertTrace(structLogs: StructLog[], startAddress: string): E // Sometimes calls don't change the execution context (current address). When we do a transfer to an // externally owned account - it does the call and immediately returns because there is no fallback // function. We manually check if the call depth had changed to handle that case. - const nextStructLog = normalizedStructLogs[i + 1]; + const nextStructLog = structLogs[i + 1]; if (nextStructLog.depth !== structLog.depth) { addressStack.push(newAddress); evmCallStack.push({ @@ -48,7 +47,7 @@ export function getRevertTrace(structLogs: StructLog[], startAddress: string): E } } else if (utils.isEndOpcode(structLog.op) && structLog.op !== OpCode.Revert) { // Just like with calls, sometimes returns/stops don't change the execution context (current address). - const nextStructLog = normalizedStructLogs[i + 1]; + const nextStructLog = structLogs[i + 1]; if (_.isUndefined(nextStructLog) || nextStructLog.depth !== structLog.depth) { evmCallStack.pop(); addressStack.pop(); @@ -76,8 +75,8 @@ export function getRevertTrace(structLogs: StructLog[], startAddress: string): E ); return []; } else { - if (structLog !== _.last(normalizedStructLogs)) { - const nextStructLog = normalizedStructLogs[i + 1]; + if (structLog !== _.last(structLogs)) { + const nextStructLog = structLogs[i + 1]; if (nextStructLog.depth === structLog.depth) { continue; } else if (nextStructLog.depth === structLog.depth - 1) { diff --git a/packages/sol-tracing-utils/src/trace.ts b/packages/sol-tracing-utils/src/trace.ts index 973452b245..1f5235455a 100644 --- a/packages/sol-tracing-utils/src/trace.ts +++ b/packages/sol-tracing-utils/src/trace.ts @@ -20,10 +20,9 @@ export function getContractAddressToTraces(structLogs: StructLog[], startAddress if (_.isEmpty(structLogs)) { return contractAddressToTraces; } - const normalizedStructLogs = utils.normalizeStructLogs(structLogs); // tslint:disable-next-line:prefer-for-of - for (let i = 0; i < normalizedStructLogs.length; i++) { - const structLog = normalizedStructLogs[i]; + for (let i = 0; i < structLogs.length; i++) { + const structLog = structLogs[i]; if (structLog.depth !== addressStack.length - 1) { throw new Error("Malformed trace. Trace depth doesn't match call stack depth"); } @@ -42,7 +41,7 @@ export function getContractAddressToTraces(structLogs: StructLog[], startAddress // Sometimes calls don't change the execution context (current address). When we do a transfer to an // externally owned account - it does the call and immediately returns because there is no fallback // function. We manually check if the call depth had changed to handle that case. - const nextStructLog = normalizedStructLogs[i + 1]; + const nextStructLog = structLogs[i + 1]; if (nextStructLog.depth !== structLog.depth) { addressStack.push(newAddress); contractAddressToTraces[currentAddress] = (contractAddressToTraces[currentAddress] || []).concat( @@ -73,8 +72,8 @@ export function getContractAddressToTraces(structLogs: StructLog[], startAddress ); return contractAddressToTraces; } else { - if (structLog !== _.last(normalizedStructLogs)) { - const nextStructLog = normalizedStructLogs[i + 1]; + if (structLog !== _.last(structLogs)) { + const nextStructLog = structLogs[i + 1]; if (nextStructLog.depth === structLog.depth) { continue; } else if (nextStructLog.depth === structLog.depth - 1) { diff --git a/packages/sol-tracing-utils/src/trace_info_subprovider.ts b/packages/sol-tracing-utils/src/trace_info_subprovider.ts index 5deb56255f..18e73aaf19 100644 --- a/packages/sol-tracing-utils/src/trace_info_subprovider.ts +++ b/packages/sol-tracing-utils/src/trace_info_subprovider.ts @@ -5,6 +5,7 @@ import { constants } from './constants'; import { getContractAddressToTraces } from './trace'; import { TraceCollectionSubprovider } from './trace_collection_subprovider'; import { SubTraceInfo, SubTraceInfoExistingContract, SubTraceInfoNewContract, TraceInfo } from './types'; +import { utils } from './utils'; // TraceInfoSubprovider is extended by subproviders which need to work with one // TraceInfo at a time. It has one abstract method: _handleTraceInfoAsync, which @@ -74,6 +75,7 @@ export abstract class TraceInfoSubprovider extends TraceCollectionSubprovider { disableStorage: true, }); } + trace.structLogs = utils.normalizeStructLogs(trace.structLogs); const traceInfo = { trace, address, From a67674bae12ecd8f7c6135352e773ed49abc8b79 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 10:54:54 -0800 Subject: [PATCH 3/8] Fix memory cost computing --- packages/sol-profiler/src/cost_utils.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/sol-profiler/src/cost_utils.ts b/packages/sol-profiler/src/cost_utils.ts index 7996f06805..2672540fc9 100644 --- a/packages/sol-profiler/src/cost_utils.ts +++ b/packages/sol-profiler/src/cost_utils.ts @@ -51,7 +51,7 @@ export const costUtils = { const length = parseInt(structLog.stack[2], HEX_BASE); return memOffset + length; } else { - return parseInt(structLog.stack[0], HEX_BASE); + return parseInt(structLog.stack[structLog.stack.length - 1], HEX_BASE); } }); const highestMemoryLocationAccessed = _.max(memoryLocationsAccessed); From 4d770549fcd59cc6247cbfeaa64143d7905c4da5 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 10:55:40 -0800 Subject: [PATCH 4/8] Fix stack content reporting in custom JS tracer --- packages/sol-tracing-utils/src/trace_info_subprovider.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/sol-tracing-utils/src/trace_info_subprovider.ts b/packages/sol-tracing-utils/src/trace_info_subprovider.ts index 18e73aaf19..f7b8af25c3 100644 --- a/packages/sol-tracing-utils/src/trace_info_subprovider.ts +++ b/packages/sol-tracing-utils/src/trace_info_subprovider.ts @@ -52,11 +52,11 @@ export abstract class TraceInfoSubprovider extends TraceCollectionSubprovider { const isCallDataAccess = opn == 0x37; var stack; if (isCall) { - stack = ['0x'+log.stack.peek(1).toString(16), null]; + stack = [null, '0x'+log.stack.peek(1).toString(16)]; } else if (isMemoryAccess) { stack = ['0x'+log.stack.peek(0).toString(16)]; } else if (isCallDataAccess) { - stack = ['0x'+log.stack.peek(2).toString(16), '0x'+log.stack.peek(1).toString(16), '0x'+log.stack.peek(0).toString(16)]; + stack = ['0x'+log.stack.peek(0).toString(16), '0x'+log.stack.peek(1).toString(16), '0x'+log.stack.peek(2).toString(16)]; } this.data.push({ pc, gasCost, depth, op, stack, gas }); }, From c3b758845dd5d78aa89fe347bc0537a88ef0db21 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 10:55:58 -0800 Subject: [PATCH 5/8] Refactor structLogs normalization to handle ganache --- packages/sol-tracing-utils/src/utils.ts | 82 +++++++++++++++++-------- 1 file changed, 57 insertions(+), 25 deletions(-) diff --git a/packages/sol-tracing-utils/src/utils.ts b/packages/sol-tracing-utils/src/utils.ts index 4c2f72b957..5067915d27 100644 --- a/packages/sol-tracing-utils/src/utils.ts +++ b/packages/sol-tracing-utils/src/utils.ts @@ -85,34 +85,66 @@ export const utils = { if (_.isEmpty(structLogs)) { return structLogs; } - if (structLogs[0].depth === 1) { - // Geth uses 1-indexed depth counter whilst ganache starts from 0 - const newStructLogs = _.map(structLogs, (structLog: StructLog, idx: number) => { - const newStructLog = { + const reduceDepthBy1 = (structLog: StructLog) => ({ + ...structLog, + depth: structLog.depth - 1, + }); + let normalizedStructLogs = structLogs; + // HACK(leo): Geth traces sometimes returns those gas costs incorrectly as very big numbers so we manually fix them. + const normalizeStaticCallCost = (structLog: StructLog) => ( + (structLog.op === OpCode.StaticCall) ? { + ...structLog, + gasCost: STATICCALL_GAS_COST, + } : structLog + ); + // HACK(leo): Geth traces sometimes returns those gas costs incorrectly as very big numbers so we manually fix them. + const normalizeCallCost = (structLog: StructLog, idx: number) => { + if (structLog.op === OpCode.Call) { + const HEX_BASE = 16; + const callAddress = parseInt(structLog.stack[0], HEX_BASE); + const MAX_REASONABLE_PRECOMPILE_ADDRESS = 100; + if (callAddress < MAX_REASONABLE_PRECOMPILE_ADDRESS) { + const nextStructLog = normalizedStructLogs[idx + 1]; + const gasCost = structLog.gas - nextStructLog.gas; + return { + ...structLog, + gasCost, + }; + } else { + return { + ...structLog, + gasCost: CALL_GAS_COST, + }; + } + } else { + return structLog; + } + }; + const shiftGasCosts1Left = (structLog: StructLog, idx: number) => { + if (idx === structLogs.length - 1) { + return { ...structLog, - depth: structLog.depth - 1, + gasCost: 0, }; - if (newStructLog.op === OpCode.StaticCall) { - // HACK(leo): Geth traces sometimes returns those gas costs incorrectly as very big numbers so we manually fix them. - newStructLog.gasCost = STATICCALL_GAS_COST; - } - if (newStructLog.op === 'CALL') { - const HEX_BASE = 16; - const callAddress = parseInt(newStructLog.stack[0], HEX_BASE); - const MAX_REASONABLE_PRECOMPILE_ADDRESS = 100; - // HACK(leo): Geth traces sometimes returns those gas costs incorrectly as very big numbers so we manually fix them. - if (callAddress < MAX_REASONABLE_PRECOMPILE_ADDRESS) { - const nextStructLog = structLogs[idx + 1]; - newStructLog.gasCost = structLog.gas - nextStructLog.gas; - } else { - newStructLog.gasCost = CALL_GAS_COST; - } - } - return newStructLog; - }); - return newStructLogs; + } else { + const nextStructLog = structLogs[idx + 1]; + const gasCost = nextStructLog.gasCost; + return { + ...structLog, + gasCost, + }; + } + }; + if (structLogs[0].depth === 1) { + // Geth uses 1-indexed depth counter whilst ganache starts from 0 + normalizedStructLogs = _.map(structLogs, reduceDepthBy1); + normalizedStructLogs = _.map(structLogs, normalizeCallCost); + normalizedStructLogs = _.map(structLogs, normalizeStaticCallCost); + } else { + // Ganache shifts opcodes gas costs so we need to unshift them + normalizedStructLogs = _.map(structLogs, shiftGasCosts1Left); } - return structLogs; + return normalizedStructLogs; }, getRange(sourceCode: string, range: SingleFileSourceRange): string { const lines = sourceCode.split('\n').slice(range.start.line - 1, range.end.line); From dbd9b1c5c4433f36d68990cdd596a38abd276338 Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 11:00:37 -0800 Subject: [PATCH 6/8] Add CHANGELOG entry --- packages/sol-profiler/CHANGELOG.json | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/packages/sol-profiler/CHANGELOG.json b/packages/sol-profiler/CHANGELOG.json index 88078d6d2b..a8876785d5 100644 --- a/packages/sol-profiler/CHANGELOG.json +++ b/packages/sol-profiler/CHANGELOG.json @@ -1,4 +1,13 @@ [ + { + "version": "3.1.0", + "changes": [ + { + "note": "Add support for Ganache", + "pr": 1647 + } + ] + }, { "version": "3.0.0", "changes": [ @@ -103,4 +112,4 @@ } ] } -] +] \ No newline at end of file From edb2a34c511680786a446c49091ad56f34e3ab25 Mon Sep 17 00:00:00 2001 From: Fabio B Date: Tue, 26 Feb 2019 13:13:56 -0800 Subject: [PATCH 7/8] Update packages/sol-tracing-utils/src/utils.ts Co-Authored-By: LogvinovLeon --- packages/sol-tracing-utils/src/utils.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/sol-tracing-utils/src/utils.ts b/packages/sol-tracing-utils/src/utils.ts index 5067915d27..04c417f1ba 100644 --- a/packages/sol-tracing-utils/src/utils.ts +++ b/packages/sol-tracing-utils/src/utils.ts @@ -98,7 +98,7 @@ export const utils = { } : structLog ); // HACK(leo): Geth traces sometimes returns those gas costs incorrectly as very big numbers so we manually fix them. - const normalizeCallCost = (structLog: StructLog, idx: number) => { + const normalizeCallCost = (structLog: StructLog, index: number) => { if (structLog.op === OpCode.Call) { const HEX_BASE = 16; const callAddress = parseInt(structLog.stack[0], HEX_BASE); From d2dc64aa2d2769ad96591471f6b6e47e48f8674e Mon Sep 17 00:00:00 2001 From: Leonid Logvinov Date: Tue, 26 Feb 2019 13:25:26 -0800 Subject: [PATCH 8/8] Rename idx to index --- packages/sol-tracing-utils/src/utils.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/sol-tracing-utils/src/utils.ts b/packages/sol-tracing-utils/src/utils.ts index 04c417f1ba..5ec8fe8718 100644 --- a/packages/sol-tracing-utils/src/utils.ts +++ b/packages/sol-tracing-utils/src/utils.ts @@ -104,7 +104,7 @@ export const utils = { const callAddress = parseInt(structLog.stack[0], HEX_BASE); const MAX_REASONABLE_PRECOMPILE_ADDRESS = 100; if (callAddress < MAX_REASONABLE_PRECOMPILE_ADDRESS) { - const nextStructLog = normalizedStructLogs[idx + 1]; + const nextStructLog = normalizedStructLogs[index + 1]; const gasCost = structLog.gas - nextStructLog.gas; return { ...structLog,