From 7ab921669bf52c1cb2d43350b2cccc8efe91bdbd Mon Sep 17 00:00:00 2001 From: Alex Browne Date: Thu, 14 Jun 2018 13:58:28 -0700 Subject: Introduce subprovider for printing revert stack traces --- packages/sol-cov/src/index.ts | 1 + packages/sol-cov/src/revert_trace.ts | 82 ++++++++ packages/sol-cov/src/revert_trace_subprovider.ts | 237 +++++++++++++++++++++++ packages/sol-cov/src/trace.ts | 41 ++-- packages/sol-cov/src/types.ts | 7 + packages/sol-cov/src/utils.ts | 24 +++ 6 files changed, 364 insertions(+), 28 deletions(-) create mode 100644 packages/sol-cov/src/revert_trace.ts create mode 100644 packages/sol-cov/src/revert_trace_subprovider.ts (limited to 'packages/sol-cov') diff --git a/packages/sol-cov/src/index.ts b/packages/sol-cov/src/index.ts index 10f6d9597..003a27374 100644 --- a/packages/sol-cov/src/index.ts +++ b/packages/sol-cov/src/index.ts @@ -1,6 +1,7 @@ export { CoverageSubprovider } from './coverage_subprovider'; // HACK: ProfilerSubprovider is a hacky way to do profiling using coverage tools. Not production ready export { ProfilerSubprovider } from './profiler_subprovider'; +export { RevertTraceSubprovider } from './revert_trace_subprovider'; export { SolCompilerArtifactAdapter } from './artifact_adapters/sol_compiler_artifact_adapter'; export { TruffleArtifactAdapter } from './artifact_adapters/truffle_artifact_adapter'; export { AbstractArtifactAdapter } from './artifact_adapters/abstract_artifact_adapter'; diff --git a/packages/sol-cov/src/revert_trace.ts b/packages/sol-cov/src/revert_trace.ts new file mode 100644 index 000000000..59edf5db4 --- /dev/null +++ b/packages/sol-cov/src/revert_trace.ts @@ -0,0 +1,82 @@ +import { logUtils } from '@0xproject/utils'; +import { OpCode, StructLog } from 'ethereum-types'; + +import * as _ from 'lodash'; + +import { EvmCallStack, EvmCallStackEntry } from './types'; +import { utils } from './utils'; + +export function getRevertTrace(structLogs: StructLog[], startAddress: string): EvmCallStack { + const evmCallStack: EvmCallStack = []; + let currentAddress = startAddress; + 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]; + if (structLog.depth !== evmCallStack.length) { + throw new Error("Malformed trace. Trace depth doesn't match call stack depth"); + } + // After that check we have a guarantee that call stack is never empty + // If it would: callStack.length - 1 === structLog.depth === -1 + // That means that we can always safely pop from it + + // TODO(albrow): split out isCallLike and isEndOpcode + if (utils.isCallLike(structLog.op)) { + const evmCallStackEntry = _.last(evmCallStack) as EvmCallStackEntry; + const prevAddress = _.isUndefined(evmCallStackEntry) ? currentAddress : evmCallStackEntry.address; + const jumpAddressOffset = 1; + currentAddress = utils.getAddressFromStackEntry( + structLog.stack[structLog.stack.length - jumpAddressOffset - 1], + ); + + if (structLog === _.last(normalizedStructLogs)) { + throw new Error('Malformed trace. CALL-like opcode can not be the last one'); + } + // 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]; + if (nextStructLog.depth !== structLog.depth) { + evmCallStack.push({ + address: prevAddress, + structLog, + }); + } + } 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]; + if (_.isUndefined(nextStructLog) || nextStructLog.depth !== structLog.depth) { + evmCallStack.pop(); + } + if (structLog.op === OpCode.SelfDestruct) { + // After contract execution, we look at all sub-calls to external contracts, and for each one, fetch + // the bytecode and compute the coverage for the call. If the contract is destroyed with a call + // to `selfdestruct`, we are unable to fetch it's bytecode and compute coverage. + // TODO: Refactor this logic to fetch the sub-called contract bytecode before the selfdestruct is called + // in order to handle this edge-case. + logUtils.warn( + "Detected a selfdestruct. Sol-cov currently doesn't support that scenario. We'll just skip the trace part for a destructed contract", + ); + } + } else if (structLog.op === OpCode.Revert) { + evmCallStack.push({ + address: currentAddress, + structLog, + }); + return evmCallStack; + } else if (structLog.op === OpCode.Create) { + // TODO: Extract the new contract address from the stack and handle that scenario + logUtils.warn( + "Detected a contract created from within another contract. Sol-cov currently doesn't support that scenario. We'll just skip that trace", + ); + return []; + } + } + if (evmCallStack.length !== 0) { + logUtils.warn('Malformed trace. Call stack non empty at the end. (probably out of gas)'); + } + return []; +} diff --git a/packages/sol-cov/src/revert_trace_subprovider.ts b/packages/sol-cov/src/revert_trace_subprovider.ts new file mode 100644 index 000000000..ea878058c --- /dev/null +++ b/packages/sol-cov/src/revert_trace_subprovider.ts @@ -0,0 +1,237 @@ +import { BlockchainLifecycle } from '@0xproject/dev-utils'; +import { Callback, ErrorCallback, NextCallback, Subprovider } from '@0xproject/subproviders'; +import { Web3Wrapper } from '@0xproject/web3-wrapper'; +import { CallData, JSONRPCRequestPayload, Provider, TxData } from 'ethereum-types'; +import { stripHexPrefix } from 'ethereumjs-util'; +import * as _ from 'lodash'; +import { getLogger, levels, Logger } from 'loglevel'; +import { Lock } from 'semaphore-async-await'; + +import { AbstractArtifactAdapter } from './artifact_adapters/abstract_artifact_adapter'; +import { constants } from './constants'; +import { getRevertTrace } from './revert_trace'; +import { parseSourceMap } from './source_maps'; +import { BlockParamLiteral, ContractData, EvmCallStack, SourceRange } from './types'; +import { utils } from './utils'; + +interface MaybeFakeTxData extends TxData { + isFakeTransaction?: boolean; +} + +const BLOCK_GAS_LIMIT = 6000000; + +/** + * This class implements the [web3-provider-engine](https://github.com/MetaMask/provider-engine) subprovider interface. + * It is used to report call stack traces whenever a revert occurs. + */ +export class RevertTraceSubprovider extends Subprovider { + // Lock is used to not accept normal transactions while doing call/snapshot magic because they'll be reverted later otherwise + private _lock = new Lock(); + private _defaultFromAddress: string; + private _web3Wrapper!: Web3Wrapper; + private _isEnabled = true; + private _artifactAdapter: AbstractArtifactAdapter; + private _contractsData!: ContractData[]; + private _logger: Logger; + + /** + * Instantiates a TraceCollectionSubprovider instance + * @param defaultFromAddress default from address to use when sending transactions + */ + constructor(artifactAdapter: AbstractArtifactAdapter, defaultFromAddress: string, isVerbose: boolean) { + super(); + this._artifactAdapter = artifactAdapter; + this._defaultFromAddress = defaultFromAddress; + this._logger = getLogger('sol-cov'); + this._logger.setLevel(isVerbose ? levels.TRACE : levels.ERROR); + } + /** + * Starts trace collection + */ + public start(): void { + this._isEnabled = true; + } + /** + * Stops trace collection + */ + public stop(): void { + this._isEnabled = false; + } + /** + * This method conforms to the web3-provider-engine interface. + * It is called internally by the ProviderEngine when it is this subproviders + * turn to handle a JSON RPC request. + * @param payload JSON RPC payload + * @param next Callback to call if this subprovider decides not to handle the request + * @param end Callback to call if subprovider handled the request and wants to pass back the request. + */ + // tslint:disable-next-line:prefer-function-over-method async-suffix + public async handleRequest(payload: JSONRPCRequestPayload, next: NextCallback, _end: ErrorCallback): Promise { + if (this._isEnabled) { + switch (payload.method) { + case 'eth_sendTransaction': + const txData = payload.params[0]; + next(this._onTransactionSentAsync.bind(this, txData)); + return; + + case 'eth_call': + const callData = payload.params[0]; + next(this._onCallOrGasEstimateExecutedAsync.bind(this, callData)); + return; + + case 'eth_estimateGas': + const estimateGasData = payload.params[0]; + next(this._onCallOrGasEstimateExecutedAsync.bind(this, estimateGasData)); + return; + + default: + next(); + return; + } + } else { + next(); + return; + } + } + /** + * Set's the subprovider's engine to the ProviderEngine it is added to. + * This is only called within the ProviderEngine source code, do not call + * directly. + */ + public setEngine(engine: Provider): void { + super.setEngine(engine); + this._web3Wrapper = new Web3Wrapper(engine); + } + private async _onTransactionSentAsync( + txData: MaybeFakeTxData, + err: Error | null, + txHash: string | undefined, + cb: Callback, + ): Promise { + if (!txData.isFakeTransaction) { + // This transaction is a usual transaction. Not a call executed as one. + // And we don't want it to be executed within a snapshotting period + await this._lock.acquire(); + } + const NULL_ADDRESS = '0x0'; + if (_.isNull(err)) { + const toAddress = + _.isUndefined(txData.to) || txData.to === NULL_ADDRESS ? constants.NEW_CONTRACT : txData.to; + await this._recordTxTraceAsync(toAddress, txData.data, txHash as string); + } else { + const latestBlock = await this._web3Wrapper.getBlockWithTransactionDataAsync(BlockParamLiteral.Latest); + const transactions = latestBlock.transactions; + for (const transaction of transactions) { + const toAddress = + _.isUndefined(txData.to) || txData.to === NULL_ADDRESS ? constants.NEW_CONTRACT : txData.to; + await this._recordTxTraceAsync(toAddress, transaction.input, transaction.hash); + } + } + if (!txData.isFakeTransaction) { + // This transaction is a usual transaction. Not a call executed as one. + // And we don't want it to be executed within a snapshotting period + this._lock.release(); + } + cb(); + } + private async _onCallOrGasEstimateExecutedAsync( + callData: Partial, + _err: Error | null, + _callResult: string, + cb: Callback, + ): Promise { + await this._recordCallOrGasEstimateTraceAsync(callData); + cb(); + } + private async _recordTxTraceAsync(address: string, data: string | undefined, txHash: string): Promise { + await this._web3Wrapper.awaitTransactionMinedAsync(txHash, 0); + const trace = await this._web3Wrapper.getTransactionTraceAsync(txHash, { + disableMemory: true, + disableStack: false, + disableStorage: true, + }); + const evmCallStack = getRevertTrace(trace.structLogs, address); + if (evmCallStack.length > 0) { + // if getRevertTrace returns a call stack it means there was a + // revert. + await this._printStackTraceAsync(evmCallStack); + } + } + private async _recordCallOrGasEstimateTraceAsync(callData: Partial): Promise { + // We don't want other transactions to be exeucted during snashotting period, that's why we lock the + // transaction execution for all transactions except our fake ones. + await this._lock.acquire(); + const blockchainLifecycle = new BlockchainLifecycle(this._web3Wrapper); + await blockchainLifecycle.startAsync(); + const fakeTxData: MaybeFakeTxData = { + gas: BLOCK_GAS_LIMIT, + isFakeTransaction: true, // This transaction (and only it) is allowed to come through when the lock is locked + ...callData, + from: callData.from || this._defaultFromAddress, + }; + try { + const txHash = await this._web3Wrapper.sendTransactionAsync(fakeTxData); + await this._web3Wrapper.awaitTransactionMinedAsync(txHash, 0); + } catch (err) { + // Even if this transaction failed - we've already recorded it's trace. + _.noop(); + } + await blockchainLifecycle.revertAsync(); + this._lock.release(); + } + private async _printStackTraceAsync(evmCallStack: EvmCallStack): Promise { + const sourceRanges: SourceRange[] = []; + if (_.isUndefined(this._contractsData)) { + this._contractsData = await this._artifactAdapter.collectContractsDataAsync(); + } + for (const evmCallStackEntry of evmCallStack) { + const isContractCreation = evmCallStackEntry.address === constants.NEW_CONTRACT; + const bytecode = await this._web3Wrapper.getContractCodeAsync(evmCallStackEntry.address); + const contractData = utils.getContractDataIfExists(this._contractsData, bytecode); + if (_.isUndefined(contractData)) { + const errMsg = isContractCreation + ? `Unknown contract creation transaction` + : `Transaction to an unknown address: ${evmCallStackEntry.address}`; + this._logger.warn(errMsg); + continue; + } + const bytecodeHex = stripHexPrefix(bytecode); + const sourceMap = isContractCreation ? contractData.sourceMap : contractData.sourceMapRuntime; + const pcToSourceRange = parseSourceMap( + contractData.sourceCodes, + sourceMap, + bytecodeHex, + contractData.sources, + ); + // tslint:disable-next-line:no-unnecessary-initializer + let sourceRange: SourceRange | undefined = undefined; + let pc = evmCallStackEntry.structLog.pc; + // Sometimes there is not a mapping for this pc (e.g. if the revert + // actually happens in assembly). In that case, we want to keep + // searching backwards by decrementing the pc until we find a + // mapped source range. + while (_.isUndefined(sourceRange)) { + sourceRange = pcToSourceRange[pc]; + pc -= 1; + if (pc <= 0) { + this._logger.warn( + `could not find matching sourceRange for structLog: ${evmCallStackEntry.structLog}`, + ); + continue; + } + } + sourceRanges.push(sourceRange); + } + if (sourceRanges.length > 0) { + this._logger.error('\n\nStack trace:\n'); + _.forEach(sourceRanges, sourceRange => { + this._logger.error( + `${sourceRange.fileName}:${sourceRange.location.start.line}:${sourceRange.location.start.column}`, + ); + }); + this._logger.error('\n'); + } else { + this._logger.error('Could not determine stack trace'); + } + } +} diff --git a/packages/sol-cov/src/trace.ts b/packages/sol-cov/src/trace.ts index 45e45e9c5..b43fd19a2 100644 --- a/packages/sol-cov/src/trace.ts +++ b/packages/sol-cov/src/trace.ts @@ -1,17 +1,13 @@ -import { addressUtils, BigNumber, logUtils } from '@0xproject/utils'; +import { logUtils } from '@0xproject/utils'; import { OpCode, StructLog } from 'ethereum-types'; -import { addHexPrefix } from 'ethereumjs-util'; import * as _ from 'lodash'; +import { utils } from './utils'; + export interface TraceByContractAddress { [contractAddress: string]: StructLog[]; } -function getAddressFromStackEntry(stackEntry: string): string { - const hexBase = 16; - return addressUtils.padZeros(new BigNumber(addHexPrefix(stackEntry)).toString(hexBase)); -} - export function getTracesByContractAddress(structLogs: StructLog[], startAddress: string): TraceByContractAddress { const traceByContractAddress: TraceByContractAddress = {}; let currentTraceSegment = []; @@ -19,13 +15,10 @@ export function getTracesByContractAddress(structLogs: StructLog[], startAddress if (_.isEmpty(structLogs)) { return traceByContractAddress; } - if (structLogs[0].depth === 1) { - // Geth uses 1-indexed depth counter whilst ganache starts from 0 - _.forEach(structLogs, structLog => structLog.depth--); - } + const normalizedStructLogs = utils.normalizeStructLogs(structLogs); // tslint:disable-next-line:prefer-for-of - for (let i = 0; i < structLogs.length; i++) { - const structLog = structLogs[i]; + for (let i = 0; i < normalizedStructLogs.length; i++) { + const structLog = normalizedStructLogs[i]; if (structLog.depth !== callStack.length - 1) { throw new Error("Malformed trace. Trace depth doesn't match call stack depth"); } @@ -34,27 +27,19 @@ export function getTracesByContractAddress(structLogs: StructLog[], startAddress // That means that we can always safely pop from it currentTraceSegment.push(structLog); - const isCallLike = _.includes( - [OpCode.CallCode, OpCode.StaticCall, OpCode.Call, OpCode.DelegateCall], - structLog.op, - ); - const isEndOpcode = _.includes( - [OpCode.Return, OpCode.Stop, OpCode.Revert, OpCode.Invalid, OpCode.SelfDestruct], - structLog.op, - ); - if (isCallLike) { + if (utils.isCallLike(structLog.op)) { const currentAddress = _.last(callStack) as string; const jumpAddressOffset = 1; - const newAddress = getAddressFromStackEntry( + const newAddress = utils.getAddressFromStackEntry( structLog.stack[structLog.stack.length - jumpAddressOffset - 1], ); - if (structLog === _.last(structLogs)) { + if (structLog === _.last(normalizedStructLogs)) { throw new Error('Malformed trace. CALL-like opcode can not be the last one'); } // 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 = structLogs[i + 1]; + const nextStructLog = normalizedStructLogs[i + 1]; if (nextStructLog.depth !== structLog.depth) { callStack.push(newAddress); traceByContractAddress[currentAddress] = (traceByContractAddress[currentAddress] || []).concat( @@ -62,7 +47,7 @@ export function getTracesByContractAddress(structLogs: StructLog[], startAddress ); currentTraceSegment = []; } - } else if (isEndOpcode) { + } else if (utils.isEndOpcode(structLog.op)) { const currentAddress = callStack.pop() as string; traceByContractAddress[currentAddress] = (traceByContractAddress[currentAddress] || []).concat( currentTraceSegment, @@ -85,8 +70,8 @@ export function getTracesByContractAddress(structLogs: StructLog[], startAddress ); return traceByContractAddress; } else { - if (structLog !== _.last(structLogs)) { - const nextStructLog = structLogs[i + 1]; + if (structLog !== _.last(normalizedStructLogs)) { + const nextStructLog = normalizedStructLogs[i + 1]; if (nextStructLog.depth === structLog.depth) { continue; } else if (nextStructLog.depth === structLog.depth - 1) { diff --git a/packages/sol-cov/src/types.ts b/packages/sol-cov/src/types.ts index 896d4a7b5..cef7141cb 100644 --- a/packages/sol-cov/src/types.ts +++ b/packages/sol-cov/src/types.ts @@ -107,3 +107,10 @@ export type TraceInfo = TraceInfoNewContract | TraceInfoExistingContract; export enum BlockParamLiteral { Latest = 'latest', } + +export interface EvmCallStackEntry { + structLog: StructLog; + address: string; +} + +export type EvmCallStack = EvmCallStackEntry[]; diff --git a/packages/sol-cov/src/utils.ts b/packages/sol-cov/src/utils.ts index 0b32df02e..4f16a1cda 100644 --- a/packages/sol-cov/src/utils.ts +++ b/packages/sol-cov/src/utils.ts @@ -1,3 +1,6 @@ +import { addressUtils, BigNumber } from '@0xproject/utils'; +import { OpCode, StructLog } from 'ethereum-types'; +import { addHexPrefix } from 'ethereumjs-util'; import * as _ from 'lodash'; import { ContractData, LineColumn, SingleFileSourceRange } from './types'; @@ -42,4 +45,25 @@ export const utils = { }); return contractData; }, + isCallLike(op: OpCode): boolean { + return _.includes([OpCode.CallCode, OpCode.StaticCall, OpCode.Call, OpCode.DelegateCall], op); + }, + isEndOpcode(op: OpCode): boolean { + return _.includes([OpCode.Return, OpCode.Stop, OpCode.Revert, OpCode.Invalid, OpCode.SelfDestruct], op); + }, + getAddressFromStackEntry(stackEntry: string): string { + const hexBase = 16; + return addressUtils.padZeros(new BigNumber(addHexPrefix(stackEntry)).toString(hexBase)); + }, + normalizeStructLogs(structLogs: StructLog[]): StructLog[] { + if (structLogs[0].depth === 1) { + // Geth uses 1-indexed depth counter whilst ganache starts from 0 + const newStructLogs = _.map(structLogs, structLog => ({ + ...structLog, + depth: structLog.depth - 1, + })); + return newStructLogs; + } + return structLogs; + }, }; -- cgit v1.2.3