Introduce subprovider for printing revert stack traces

6 files changed, 364 insertions, 28 deletions

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<void> {
+        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<void> {
+        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<CallData>,
+        _err: Error | null,
+        _callResult: string,
+        cb: Callback,
+    ): Promise<void> {
+        await this._recordCallOrGasEstimateTraceAsync(callData);
+        cb();
+    }
+    private async _recordTxTraceAsync(address: string, data: string | undefined, txHash: string): Promise<void> {
+        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<CallData>): Promise<void> {
+        // 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<void> {
+        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;
+    },
 };