diff --git a/mythril/__version__.py b/mythril/__version__.py index 2caa19c4..bf5928a9 100644 --- a/mythril/__version__.py +++ b/mythril/__version__.py @@ -4,4 +4,4 @@ This file is suitable for sourcing inside POSIX shell, e.g. bash as well as for importing into Python. """ -__version__ = "v0.22.7" +__version__ = "v0.22.8" diff --git a/mythril/analysis/report.py b/mythril/analysis/report.py index d40c466b..3a8c650d 100644 --- a/mythril/analysis/report.py +++ b/mythril/analysis/report.py @@ -3,9 +3,10 @@ import logging import json import operator from jinja2 import PackageLoader, Environment -from typing import Dict, List +from typing import Dict, List, Any, Optional import hashlib +from mythril.laser.execution_info import ExecutionInfo from mythril.solidity.soliditycontract import SolidityContract from mythril.analysis.swc_data import SWC_TO_TITLE from mythril.support.source_support import Source @@ -184,18 +185,24 @@ class Report: loader=PackageLoader("mythril.analysis"), trim_blocks=True ) - def __init__(self, contracts=None, exceptions=None): + def __init__( + self, + contracts=None, + exceptions=None, + execution_info: Optional[List[ExecutionInfo]] = None, + ): """ :param contracts: :param exceptions: """ - self.issues = {} + self.issues = {} # type: Dict[bytes, Issue] self.solc_version = "" - self.meta = {} + self.meta = {} # type: Dict[str, Any] self.source = Source() self.source.get_source_from_contracts_list(contracts) self.exceptions = exceptions or [] + self.execution_info = execution_info or [] def sorted_issues(self): """ @@ -246,6 +253,7 @@ class Report: :return: """ + # Setup issues _issues = [] for key, issue in self.issues.items(): @@ -272,7 +280,17 @@ class Report: "extra": extra, } ) - meta_data = self._get_exception_data() + # Setup meta + meta_data = self.meta + + # Add logs to meta + meta_data.update(self._get_exception_data()) + + # Add execution info to meta + meta_data["mythril_execution_info"] = {} + for execution_info in self.execution_info: + meta_data["mythril_execution_info"].update(execution_info.as_dict()) + result = [ { "issues": _issues, diff --git a/mythril/analysis/symbolic.py b/mythril/analysis/symbolic.py index 88e3882b..35e3517c 100644 --- a/mythril/analysis/symbolic.py +++ b/mythril/analysis/symbolic.py @@ -2,8 +2,8 @@ purposes.""" from mythril.analysis.module import EntryPoint, ModuleLoader, get_detection_module_hooks +from mythril.laser.execution_info import ExecutionInfo from mythril.laser.ethereum import svm -from mythril.laser.ethereum.iprof import InstructionProfiler from mythril.laser.ethereum.state.account import Account from mythril.laser.ethereum.state.world_state import WorldState from mythril.laser.ethereum.strategy.basic import ( @@ -24,6 +24,7 @@ from mythril.laser.plugin.plugins import ( DependencyPrunerBuilder, CoveragePluginBuilder, CallDepthLimitBuilder, + InstructionProfilerBuilder, ) from mythril.laser.ethereum.strategy.extensions.bounded_loops import ( BoundedLoopsStrategy, @@ -55,7 +56,6 @@ class SymExecWrapper: transaction_count: int = 2, modules: Optional[List[str]] = None, compulsory_statespace: bool = True, - iprof: Optional[InstructionProfiler] = None, disable_dependency_pruning: bool = False, run_analysis_modules: bool = True, custom_modules_directory: str = "", @@ -121,7 +121,6 @@ class SymExecWrapper: create_timeout=create_timeout, transaction_count=transaction_count, requires_statespace=requires_statespace, - iprof=iprof, ) if loop_bound is not None: @@ -131,9 +130,11 @@ class SymExecWrapper: plugin_loader.load(CoveragePluginBuilder()) plugin_loader.load(MutationPrunerBuilder()) plugin_loader.load(CallDepthLimitBuilder()) + plugin_loader.load(InstructionProfilerBuilder()) plugin_loader.add_args( "call-depth-limit", call_depth_limit=args.call_depth_limit ) + if not disable_dependency_pruning: plugin_loader.load(DependencyPrunerBuilder()) @@ -300,3 +301,7 @@ class SymExecWrapper: ) state_index += 1 + + @property + def execution_info(self) -> List[ExecutionInfo]: + return self.laser.execution_info diff --git a/mythril/ethereum/util.py b/mythril/ethereum/util.py index 0ec4e645..c676611e 100644 --- a/mythril/ethereum/util.py +++ b/mythril/ethereum/util.py @@ -14,6 +14,7 @@ from mythril.exceptions import CompilerError if sys.version_info[1] >= 6: import solcx + from solcx.exceptions import SolcNotInstalled def safe_decode(hex_encoded_string): @@ -131,12 +132,15 @@ def solc_exists(version): "bin/solc", ) # py-solc setup ] + for solc_path in solc_binaries: + if os.path.exists(solc_path): + return solc_path elif sys.version_info[1] >= 6: # we are using solc-x for the the 0.5 and higher - solc_binaries = [os.path.join(solcx.__path__[0], "bin", "solc-v" + version)] - for solc_path in solc_binaries: - if os.path.exists(solc_path): - return solc_path + try: + return solcx.install.get_executable(version) + except SolcNotInstalled: + pass # Last resort is to use the system installation default_binary = "/usr/bin/solc" diff --git a/mythril/laser/ethereum/instructions.py b/mythril/laser/ethereum/instructions.py index 28c34fd0..ff29cc82 100644 --- a/mythril/laser/ethereum/instructions.py +++ b/mythril/laser/ethereum/instructions.py @@ -4,7 +4,7 @@ import binascii import logging from copy import copy, deepcopy -from typing import cast, Callable, List, Union +from typing import cast, Callable, List, Union, Optional from datetime import datetime from mythril.laser.smt import ( @@ -202,7 +202,13 @@ class Instruction: """Instruction class is used to mutate a state according to the current instruction.""" - def __init__(self, op_code: str, dynamic_loader: DynLoader, iprof=None) -> None: + def __init__( + self, + op_code: str, + dynamic_loader: DynLoader, + pre_hooks: List[Callable] = None, + post_hooks: List[Callable] = None, + ) -> None: """ :param op_code: @@ -211,7 +217,16 @@ class Instruction: """ self.dynamic_loader = dynamic_loader self.op_code = op_code.upper() - self.iprof = iprof + self.pre_hook = pre_hooks if pre_hooks else [] + self.post_hook = post_hooks if post_hooks else [] + + def _execute_pre_hooks(self, global_state: GlobalState): + for hook in self.pre_hook: + hook(global_state) + + def _execute_post_hooks(self, global_state: GlobalState): + for hook in self.post_hook: + hook(global_state) def evaluate(self, global_state: GlobalState, post=False) -> List[GlobalState]: """Performs the mutation for this instruction. @@ -241,13 +256,10 @@ class Instruction: if instruction_mutator is None: raise NotImplementedError - if self.iprof is None: - result = instruction_mutator(global_state) - else: - start_time = datetime.now() - result = instruction_mutator(global_state) - end_time = datetime.now() - self.iprof.record(op, start_time, end_time) + self._execute_pre_hooks(global_state) + + result = instruction_mutator(global_state) + self._execute_post_hooks(global_state) return result diff --git a/mythril/laser/ethereum/svm.py b/mythril/laser/ethereum/svm.py index dd286bbf..97f5712f 100644 --- a/mythril/laser/ethereum/svm.py +++ b/mythril/laser/ethereum/svm.py @@ -5,7 +5,9 @@ from copy import copy from datetime import datetime, timedelta from typing import Callable, Dict, DefaultDict, List, Tuple, Optional +from mythril.support.opcodes import opcodes as OPCODES from mythril.analysis.potential_issues import check_potential_issues +from mythril.laser.execution_info import ExecutionInfo from mythril.laser.ethereum.cfg import NodeFlags, Node, Edge, JumpType from mythril.laser.ethereum.evm_exceptions import StackUnderflowException from mythril.laser.ethereum.evm_exceptions import VmException @@ -71,8 +73,9 @@ class LaserEVM: :param requires_statespace: Variable indicating whether the statespace should be recorded :param iprof: Instruction Profiler """ - self.open_states = [] # type: List[WorldState] + self.execution_info = [] # type: List[ExecutionInfo] + self.open_states = [] # type: List[WorldState] self.total_states = 0 self.dynamic_loader = dynamic_loader @@ -105,7 +108,11 @@ class LaserEVM: self._stop_sym_exec_hooks = [] # type: List[Callable] self.iprof = iprof - + self.instr_pre_hook = {} # type: Dict[str, List[Callable]] + self.instr_post_hook = {} # type: Dict[str, List[Callable]] + for op, _, _, _ in OPCODES.values(): + self.instr_pre_hook[op] = [] + self.instr_post_hook[op] = [] log.info("LASER EVM initialized with dynamic loader: " + str(dynamic_loader)) def extend_strategy(self, extension: ABCMeta, *args) -> None: @@ -176,9 +183,6 @@ class LaserEVM: self.total_states, ) - if self.iprof is not None: - log.info("Instruction Statistics:\n{}".format(self.iprof)) - for hook in self._stop_sym_exec_hooks: hook() @@ -331,7 +335,10 @@ class LaserEVM: try: new_global_states = Instruction( - op_code, self.dynamic_loader, self.iprof + op_code, + self.dynamic_loader, + pre_hooks=self.instr_pre_hook[op_code], + post_hooks=self.instr_post_hook[op_code], ).evaluate(global_state) except VmException as e: @@ -443,7 +450,10 @@ class LaserEVM: # Execute the post instruction handler new_global_states = Instruction( - op_code, self.dynamic_loader, self.iprof + op_code, + self.dynamic_loader, + pre_hooks=self.instr_pre_hook[op_code], + post_hooks=self.instr_post_hook[op_code], ).evaluate(return_global_state, True) # In order to get a nice call graph we need to set the nodes here @@ -579,6 +589,37 @@ class LaserEVM: "Invalid hook type %s. Must be one of {add_world_state}", hook_type ) + def register_instr_hooks(self, hook_type: str, opcode: str, hook: Callable): + """Registers instructions hooks from plugins""" + if hook_type == "pre": + if opcode is None: + for op, _, _, _ in OPCODES.values(): + self.instr_pre_hook[op].append(hook(op)) + else: + self.instr_pre_hook[opcode].append(hook) + else: + if opcode is None: + for op, _, _, _ in OPCODES.values(): + self.instr_post_hook[op].append(hook(op)) + else: + self.instr_post_hook[opcode].append(hook) + + def instr_hook(self, hook_type, opcode) -> Callable: + """Registers the annoted function with register_instr_hooks + + :param hook_type: Type of hook pre/post + :param opcode: The opcode related to the function + """ + + def hook_decorator(func: Callable): + """ Hook decorator generated by laser_hook + + :param func: Decorated function + """ + self.register_instr_hooks(hook_type, opcode, func) + + return hook_decorator + def laser_hook(self, hook_type: str) -> Callable: """Registers the annotated function with register_laser_hooks diff --git a/mythril/laser/execution_info.py b/mythril/laser/execution_info.py new file mode 100644 index 00000000..641ff160 --- /dev/null +++ b/mythril/laser/execution_info.py @@ -0,0 +1,11 @@ +from abc import ABC, abstractmethod + + +class ExecutionInfo(ABC): + @abstractmethod + def as_dict(self): + """Returns a dictionary with the execution info contained in this object + + The returned dictionary only uses primitive types. + """ + pass diff --git a/mythril/laser/plugin/plugins/__init__.py b/mythril/laser/plugin/plugins/__init__.py index 04722dde..ee9fdc6a 100644 --- a/mythril/laser/plugin/plugins/__init__.py +++ b/mythril/laser/plugin/plugins/__init__.py @@ -10,3 +10,4 @@ from mythril.laser.plugin.plugins.coverage.coverage_plugin import CoveragePlugin from mythril.laser.plugin.plugins.dependency_pruner import DependencyPrunerBuilder from mythril.laser.plugin.plugins.mutation_pruner import MutationPrunerBuilder from mythril.laser.plugin.plugins.call_depth_limiter import CallDepthLimitBuilder +from mythril.laser.plugin.plugins.instruction_profiler import InstructionProfilerBuilder diff --git a/mythril/laser/plugin/plugins/instruction_profiler.py b/mythril/laser/plugin/plugins/instruction_profiler.py new file mode 100644 index 00000000..623dd558 --- /dev/null +++ b/mythril/laser/plugin/plugins/instruction_profiler.py @@ -0,0 +1,116 @@ +from collections import namedtuple +from datetime import datetime +from typing import Dict, List, Tuple +from mythril.laser.plugin.builder import PluginBuilder +from mythril.laser.plugin.interface import LaserPlugin +from mythril.laser.ethereum.svm import LaserEVM +from mythril.laser.ethereum.state.global_state import GlobalState +from datetime import datetime +import logging + +# Type annotations: +# start_time: datetime +# end_time: datetime +_InstrExecRecord = namedtuple("_InstrExecRecord", ["start_time", "end_time"]) + +# Type annotations: +# total_time: float +# total_nr: float +# min_time: float +# max_time: float +_InstrExecStatistic = namedtuple( + "_InstrExecStatistic", ["total_time", "total_nr", "min_time", "max_time"] +) + +# Map the instruction opcode to its records if all execution times +_InstrExecRecords = Dict[str, List[_InstrExecRecord]] + +# Map the instruction opcode to the statistic of its execution times +_InstrExecStatistics = Dict[str, _InstrExecStatistic] + +log = logging.getLogger(__name__) + + +class InstructionProfilerBuilder(PluginBuilder): + plugin_name = "dependency-pruner" + + def __call__(self, *args, **kwargs): + return InstructionProfiler() + + +class InstructionProfiler(LaserPlugin): + """Performance profile for the execution of each instruction. + """ + + def __init__(self): + self._reset() + + def _reset(self): + self.records = dict() + self.start_time = None + + def initialize(self, symbolic_vm: LaserEVM) -> None: + @symbolic_vm.instr_hook("pre", None) + def get_start_time(op_code: str): + def start_time_wrapper(global_state: GlobalState): + self.start_time = datetime.now() + + return start_time_wrapper + + @symbolic_vm.instr_hook("post", None) + def record(op_code: str): + def record_opcode(global_state: GlobalState): + end_time = datetime.now() + try: + self.records[op_code].append( + _InstrExecRecord(self.start_time, end_time) + ) + except KeyError: + self.records[op_code] = [ + _InstrExecRecord(self.start_time, end_time) + ] + + return record_opcode + + @symbolic_vm.laser_hook("stop_sym_exec") + def print_stats(): + total, stats = self._make_stats() + + s = "Total: {} s\n".format(total) + + for op in sorted(stats): + stat = stats[op] + s += "[{:12s}] {:>8.4f} %, nr {:>6}, total {:>8.4f} s, avg {:>8.4f} s, min {:>8.4f} s, max {:>8.4f} s\n".format( + op, + stat.total_time * 100 / total, + stat.total_nr, + stat.total_time, + stat.total_time / stat.total_nr, + stat.min_time, + stat.max_time, + ) + + log.info(s) + + def _make_stats(self) -> Tuple[float, _InstrExecStatistics]: + periods = { + op: list( + map(lambda r: r.end_time.timestamp() - r.start_time.timestamp(), rs) + ) + for op, rs in self.records.items() + } + + stats = dict() + total_time = 0 + + for _, (op, times) in enumerate(periods.items()): + stat = _InstrExecStatistic( + total_time=sum(times), + total_nr=len(times), + min_time=min(times), + max_time=max(times), + ) + total_time += stat.total_time + stats[op] = stat + + return total_time, stats diff --git a/mythril/mythril/mythril_analyzer.py b/mythril/mythril/mythril_analyzer.py index a95fabc0..b0795cb7 100644 --- a/mythril/mythril/mythril_analyzer.py +++ b/mythril/mythril/mythril_analyzer.py @@ -19,6 +19,7 @@ from mythril.ethereum.evmcontract import EVMContract from mythril.laser.smt import SolverStatistics from mythril.support.start_time import StartTime from mythril.exceptions import DetectorNotFoundError +from mythril.laser.execution_info import ExecutionInfo log = logging.getLogger(__name__) @@ -65,7 +66,6 @@ class MythrilAnalyzer: self.execution_timeout = execution_timeout self.loop_bound = loop_bound self.create_timeout = create_timeout - self.iprof = InstructionProfiler() if enable_iprof else None self.disable_dependency_pruning = disable_dependency_pruning self.custom_modules_directory = custom_modules_directory args.sparse_pruning = sparse_pruning @@ -73,6 +73,7 @@ class MythrilAnalyzer: args.parallel_solving = parallel_solving args.unconstrained_storage = unconstrained_storage args.call_depth_limit = call_depth_limit + args.iprof = enable_iprof def dump_statespace(self, contract: EVMContract = None) -> str: """ @@ -88,7 +89,6 @@ class MythrilAnalyzer: max_depth=self.max_depth, execution_timeout=self.execution_timeout, create_timeout=self.create_timeout, - iprof=self.iprof, disable_dependency_pruning=self.disable_dependency_pruning, run_analysis_modules=False, custom_modules_directory=self.custom_modules_directory, @@ -121,7 +121,6 @@ class MythrilAnalyzer: execution_timeout=self.execution_timeout, transaction_count=transaction_count, create_timeout=self.create_timeout, - iprof=self.iprof, disable_dependency_pruning=self.disable_dependency_pruning, run_analysis_modules=False, custom_modules_directory=self.custom_modules_directory, @@ -141,6 +140,7 @@ class MythrilAnalyzer: all_issues = [] # type: List[Issue] SolverStatistics().enabled = True exceptions = [] + execution_info = None # type: Optional[List[ExecutionInfo]] for contract in self.contracts: StartTime() # Reinitialize start time for new contracts try: @@ -156,18 +156,16 @@ class MythrilAnalyzer: transaction_count=transaction_count, modules=modules, compulsory_statespace=False, - iprof=self.iprof, disable_dependency_pruning=self.disable_dependency_pruning, custom_modules_directory=self.custom_modules_directory, ) issues = fire_lasers(sym, modules) + execution_info = sym.execution_info except DetectorNotFoundError as e: # Bubble up raise e except KeyboardInterrupt: log.critical("Keyboard Interrupt") - if self.iprof is not None: - log.info("Instruction Statistics:\n{}".format(self.iprof)) issues = retrieve_callback_issues(modules) except Exception: log.critical( @@ -176,8 +174,6 @@ class MythrilAnalyzer: ) issues = retrieve_callback_issues(modules) exceptions.append(traceback.format_exc()) - if self.iprof is not None: - log.info("Instruction Statistics:\n{}".format(self.iprof)) for issue in issues: issue.add_code_info(contract) @@ -186,8 +182,13 @@ class MythrilAnalyzer: source_data = Source() source_data.get_source_from_contracts_list(self.contracts) + # Finally, output the results - report = Report(contracts=self.contracts, exceptions=exceptions) + report = Report( + contracts=self.contracts, + exceptions=exceptions, + execution_info=execution_info, + ) for issue in all_issues: report.append_issue(issue) diff --git a/mythril/support/support_args.py b/mythril/support/support_args.py index eef18764..9f99f63b 100644 --- a/mythril/support/support_args.py +++ b/mythril/support/support_args.py @@ -10,6 +10,7 @@ class Args: self.unconstrained_storage = False self.parallel_solving = False self.call_depth_limit = 3 + self.iprof = True args = Args() diff --git a/requirements.txt b/requirements.txt index f36751af..fac4b6ec 100644 --- a/requirements.txt +++ b/requirements.txt @@ -18,7 +18,7 @@ persistent>=4.2.0 plyvel py-flags py-evm==0.3.0a13 -py-solc-x==0.6.0 +py-solc-x==0.10.0 py-solc pytest>=3.6.0 pytest-cov diff --git a/tests/mythril/mythril_analyzer_test.py b/tests/mythril/mythril_analyzer_test.py index 0e826cc8..2f100ac1 100644 --- a/tests/mythril/mythril_analyzer_test.py +++ b/tests/mythril/mythril_analyzer_test.py @@ -1,7 +1,7 @@ from pathlib import Path from mythril.mythril import MythrilDisassembler, MythrilAnalyzer from mythril.analysis.report import Issue -from mock import patch +from mock import patch, PropertyMock @patch("mythril.analysis.report.Issue.add_code_info", return_value=None) @@ -9,8 +9,9 @@ from mock import patch "mythril.mythril.mythril_analyzer.fire_lasers", return_value=[Issue("", "", "234", "101", "title", "0x02445")], ) -@patch("mythril.mythril.mythril_analyzer.SymExecWrapper", return_value=None) +@patch("mythril.mythril.mythril_analyzer.SymExecWrapper") def test_fire_lasers(mock_sym, mock_fire_lasers, mock_code_info): + type(mock_sym.return_value).execution_info = PropertyMock(return_value=[]) disassembler = MythrilDisassembler(eth=None) disassembler.load_from_solidity( [