DeforaNetworks/manticore
3
0
Fork 0
Code Releases Activity

EVM logging cleanup (#647)

Browse Source 
* make init_logging() idempotent

* Update logger names; add plugin logger

* Add logging support to main

* Start tracking completed transactions as part of ManticoreEVM

* Make evm and non evm output more consistent

* Remove redundant start_workers

* make debug output conditional in Manticore

* Improve seth logging

* Add seth to logger lists and make sure new loggers are initialized

* Make completed_transactions not lie during the processing of one

* Print coverage after processing a transaction

* Demote starting msg to debug
This commit is contained in:
Yan Ivnitskiy 2017-12-18 16:06:44 -05:00 committed by Mark Mossberg
parent 6dd50da350
commit 591d7b81d5
5 changed files with 46 additions and 56 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

23
manticore/__main__.py
View File

@ -1,10 +1,17 @@
import sys
import logging
import argparse
from manticore import Manticore
from . import Manticore
from .utils import log
# XXX(yan): This would normally be __name__, but then logger output will be pre-
# pended by 'm.__main__: ', which is not very pleasing. hard-coding to 'main'
logger = logging.getLogger('manticore.main')
sys.setrecursionlimit(10000)
def parse_arguments():
###########################################################################
# parse arguments
@ -66,6 +73,7 @@ def parse_arguments():
def ethereum_cli(args):
from seth import ManticoreEVM, IntegerOverflow, UnitializedStorage, UnitializedMemory
log.init_logging()
m = ManticoreEVM(procs=args.procs)
@ -82,9 +90,10 @@ def ethereum_cli(args):
contract_account = m.solidity_create_contract(source_code, owner=user_account)
attacker_account = m.create_account(balance=1000)
logger.info("Starting with %d processes", args.procs)
last_coverage = None
new_coverage = 0
tx_count = 0
while new_coverage != last_coverage and new_coverage < 100:
symbolic_data = m.make_symbolic_buffer(320)
@ -95,21 +104,13 @@ def ethereum_cli(args):
data=symbolic_data,
value=symbolic_value )
tx_count += 1
last_coverage = new_coverage
new_coverage = m.global_coverage(contract_account)
print "[+] Coverage after %d transactions: %d%%"%(tx_count, new_coverage)
print "[+] There are %d reverted states now"% len(m.terminated_state_ids)
print "[+] There are %d alive states now"% len(m.running_state_ids)
m.finalize()
print "[+] Look for results in %s"% m.workspace
def main():
log.init_logging()
args = parse_arguments()
Manticore.verbosity(args.v)

2
manticore/core/plugin.py
View File

@ -3,7 +3,7 @@ import logging
from capstone import CS_GRP_JUMP
from ..utils.helpers import issymbolic
logger = logging.getLogger('MANTICORE')
logger = logging.getLogger(__name__)
class Plugin(object):

36
manticore/manticore.py
View File

@ -358,40 +358,6 @@ class Manticore(Eventful):
''' Dynamically enqueue states. Users should typically not need to do this '''
self._executor.add(state)
###########################################################################
# Workers #
###########################################################################
def _start_workers(self, num_processes, profiling=False):
assert num_processes > 0, "Must have more than 0 worker processes"
logger.info("Starting %d processes.", num_processes)
if profiling:
def profile_this(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
profile = cProfile.Profile()
profile.enable()
result = func(*args, **kwargs)
profile.disable()
profile.create_stats()
with self.locked_context('profiling_stats', list) as profiling_stats:
profiling_stats.append(profile.stats.items())
return result
return wrapper
target = profile_this(self._executor.run)
else:
target = self._executor.run
if num_processes == 1:
target()
else:
for _ in range(num_processes):
p = Process(target=target, args=())
self._workers.append(p)
p.start()
@property
def running(self):
return self._executor.running
@ -407,7 +373,7 @@ class Manticore(Eventful):
def _start_workers(self, num_processes, profiling=False):
assert num_processes > 0, "Must have more than 0 worker processes"
logger.info("Starting %d processes.", num_processes)
logger.debug("Starting %d processes.", num_processes)
if profiling:
def profile_this(func):

24
manticore/seth.py
View File

@ -369,7 +369,6 @@ class ABI(object):
size = get_uint(256, dyn_offset)
return data[dyn_offset+32:dyn_offset+32+size], offset+4
else:
print "<",ty,">"
raise NotImplemented(ty)
@staticmethod
@ -584,6 +583,7 @@ class ManticoreEVM(Manticore):
self.context['seth']['_pending_transaction'] = None
self.context['seth']['_saved_states'] = []
self.context['seth']['_final_states'] = []
self.context['seth']['_completed_transactions'] = 0
self._executor.subscribe('did_load_state', self._load_state_callback)
self._executor.subscribe('will_terminate_state', self._terminate_state_callback)
@ -598,6 +598,11 @@ class ManticoreEVM(Manticore):
''' The world instance or None if there is more than one state '''
return self.get_world(None)
@property
def completed_transactions(self):
with self.locked_context('seth') as context:
return context['_completed_transactions']
@property
def running_state_ids(self):
''' IDs of the running states'''
@ -797,7 +802,17 @@ class ManticoreEVM(Manticore):
data = (None,)*data.size
with self.locked_context('seth') as context:
context['_pending_transaction'] = ('CALL', caller, address, value, data)
return self.run(procs=self._config_procs)
status = self.run(procs=self._config_procs)
with self.locked_context('seth') as context:
context['_completed_transactions'] = context['_completed_transactions'] + 1
logger.info("Coverage after %d transactions: %d%%", self.completed_transactions, self.global_coverage(address))
logger.info("There are %d reverted states now", len(self.terminated_state_ids))
logger.info("There are %d alive states now", len(self.running_state_ids))
return status
def run(self, **kwargs):
''' Run any pending transaction on any running state '''
@ -942,7 +957,6 @@ class ManticoreEVM(Manticore):
assert state.constraints == state.platform.constraints
assert state.platform.constraints == state.platform.current.constraints
logger.debug("%s", state.platform.current)
#print state.platform.current
if 'Call' in str(type(state.platform.current.last_exception)):
coverage_context_name = 'runtime_coverage'
@ -1225,7 +1239,7 @@ class ManticoreEVM(Manticore):
f.write('0x%x\n'%o)
logger.info("[+] Look for results in %s", self.workspace )
logger.info("Look for results in %s", self.workspace )
def global_coverage(self, account_address):
''' Returns code coverage for the contract on `account_address`.
@ -1258,4 +1272,4 @@ class ManticoreEVM(Manticore):
#TODO: find a better way to suppress execution of Manticore._did_finish_run_callback
def _did_finish_run_callback(self):
_shared_context = self.context

17
manticore/utils/log.py
View File

@ -29,7 +29,7 @@ all_loggers = []
def init_logging():
global all_loggers
all_loggers = logging.getLogger().manager.loggerDict.keys()
loggers = logging.getLogger().manager.loggerDict.keys()
ctxfilter = ContextFilter()
logfmt = ("%(asctime)s: [%(process)d]%(stateid)s %(name)s:%(levelname)s:"
@ -37,15 +37,19 @@ def init_logging():
handler = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter(logfmt)
handler.setFormatter(formatter)
for name in all_loggers:
for name in loggers:
logger = logging.getLogger(name)
if not name.startswith('manticore'):
continue
if name in all_loggers:
continue
logger.addHandler(handler)
logger.propagate = False
logger.setLevel(logging.WARNING)
logger.addFilter(ctxfilter)
logger.setState = types.MethodType(loggerSetState, logger)
all_loggers.append(name)
set_verbosity(manticore_verbosity)
def loggerSetState(logger, stateid):
logger.filters[0].stateid = stateid
@ -58,12 +62,16 @@ def set_verbosity(setting):
zero,
# 1
[
('manticore.manticore', logging.INFO)
('manticore.manticore', logging.INFO),
('manticore.main', logging.INFO),
('manticore.seth', logging.INFO),
],
# 2 (-v)
[
('manticore.core.executor', logging.INFO),
('manticore.platforms.*', logging.DEBUG)
('manticore.platforms.*', logging.DEBUG),
('manticore.seth', logging.DEBUG),
('manticore.core.plugin', logging.DEBUG),
],
# 3 (-vv)
[
@ -111,4 +119,5 @@ def set_verbosity(setting):
for logger_name in glob(all_loggers, pattern):
logger = logging.getLogger(logger_name)
logger.setLevel(log_level)
manticore_verbosity = clamped