Merge pull request #321 from ethereum/clean_up_tests

Cleanup test loading

Author: konradkonrad

.travis.yml

@@ -4,8 +4,8 @@ sudo: false
 env:
 - TOX_ENV=py27
 install:
-- pip install -r requirements.txt
-- pip install -r dev_requirements.txt
+- pip install -Ur requirements.txt
+- pip install -Ur dev_requirements.txt
 script:
 - coverage run --source ethereum -m py.test --ignore ethereum/tests/test_vm.py --ignore
   ethereum/tests/test_state.py

dev_requirements.txt

@@ -1,6 +1,6 @@
 tox
 coveralls
-pytest
-pytest-catchlog==1.1
-pytest-timeout==0.5
+pytest>=2.9.0
+pytest-catchlog==1.2.2
+pytest-timeout==1.0.0
 https://github.com/ethereum/serpent/tarball/develop

ethereum/slogging.py

@@ -35,15 +35,32 @@ class LogRecorder(object):
     """
     max_capacity = 1000 * 1000  # check we are not forgotten or abused
 
-    def __init__(self):
+    def __init__(self, disable_other_handlers=False, log_config=None):
         self._records = []
         log_listeners.append(self._add_log_record)
+        self._saved_config = None
+        if log_config:
+            self._saved_config = get_configuration()
+            configure(log_config)
+        self._saved_handlers = []
+        if disable_other_handlers:
+            self._saved_handlers = rootLogger.handlers[:]
+            rootLogger.handlers = []
 
     def pop_records(self):
-        # can only be called once
+        # only returns records on the first call
         r = self._records[:]
-        self._records = None
-        log_listeners.remove(self._add_log_record)
+        self._records = []
+        try:
+            log_listeners.remove(self._add_log_record)
+        except ValueError:
+            pass
+        if self._saved_config:
+            configure(**self._saved_config)
+            self._saved_config = None
+        if self._saved_handlers:
+            rootLogger.handlers = self._saved_handlers[:]
+            self._saved_handlers = []
         return r
 
     def _add_log_record(self, msg):
@@ -59,9 +76,13 @@ def get_configuration():
     """
     root = getLogger()
     name_levels = [('', logging.getLevelName(root.level))]
+    name_levels.extend(
+        (name, logging.getLevelName(logger.level))
+        for name, logger
+        in root.manager.loggerDict.items()
+        if hasattr(logger, 'level')
+    )
 
-    for name, logger in list(root.manager.loggerDict.items()):
-        name_levels.append((name, logging.getLevelName(logger.level)))
     config_string = ','.join('%s:%s' % x for x in name_levels)
 
     return dict(config_string=config_string, log_json=root.log_json)
@@ -222,6 +243,7 @@ def configure(config_string=None, log_json=False, log_file=None):
         if hasattr(logger, 'setLevel'):
             # Guard against `logging.PlaceHolder` instances
             logger.setLevel(logging.NOTSET)
+            logger.propagate = True
 
     for name_levels in config_string.split(','):
         name, _, level = name_levels.partition(':')

ethereum/tester.py

@@ -13,6 +13,17 @@
 import rlp
 from rlp.utils import decode_hex, encode_hex, ascii_chr
 
+
+TRACE_LVL_MAP = [
+    ':info',
+    'eth.vm.log:trace',
+    ':info,eth.vm.log:trace,eth.vm.exit:trace',
+    ':info,eth.vm.log:trace,eth.vm.op:trace,eth.vm.stack:trace',
+    ':info,eth.vm.log:trace,eth.vm.op:trace,eth.vm.stack:trace,' +
+    'eth.vm.storage:trace,eth.vm.memory:trace'
+]
+
+
 serpent = None
 
 u = ethereum.utils
@@ -199,31 +210,35 @@ def _send(self, sender, to, value, evmdata='', output=None,
         tx = t.Transaction(sendnonce, gas_price, gas_limit, to, value, evmdata)
         self.last_tx = tx
         tx.sign(sender)
+        recorder = None
         if profiling > 1:
-            set_logging_level(3)
-            recorder = LogRecorder()
-        (s, o) = pb.apply_transaction(self.block, tx)
-        if not s:
-            raise TransactionFailed()
-        out = {"output": o}
-        if profiling > 0:
-            zero_bytes = tx.data.count(ascii_chr(0))
-            non_zero_bytes = len(tx.data) - zero_bytes
-            intrinsic_gas_used = opcodes.GTXCOST + \
-                opcodes.GTXDATAZERO * zero_bytes + \
-                opcodes.GTXDATANONZERO * non_zero_bytes
-            ntm, ng = time.time(), self.block.gas_used
-            out["time"] = ntm - tm
-            out["gas"] = ng - g - intrinsic_gas_used
-        if profiling > 1:
-            trace = recorder.pop_records()
-            set_logging_level(0)
-            ops = [x['op'] for x in trace if x['event'] == 'vm']
-            opdict = {}
-            for op in ops:
-                opdict[op] = opdict.get(op, 0) + 1
-            out["ops"] = opdict
-        return out
+            recorder = LogRecorder(disable_other_handlers=True, log_config=TRACE_LVL_MAP[3])
+        try:
+            (s, o) = pb.apply_transaction(self.block, tx)
+            if not s:
+                raise TransactionFailed()
+            out = {"output": o}
+            if profiling > 0:
+                zero_bytes = tx.data.count(ascii_chr(0))
+                non_zero_bytes = len(tx.data) - zero_bytes
+                intrinsic_gas_used = opcodes.GTXCOST + \
+                    opcodes.GTXDATAZERO * zero_bytes + \
+                    opcodes.GTXDATANONZERO * non_zero_bytes
+                ntm, ng = time.time(), self.block.gas_used
+                out["time"] = ntm - tm
+                out["gas"] = ng - g - intrinsic_gas_used
+            if profiling > 1:
+                trace = recorder.pop_records()
+                ops = [x['op'] for x in trace if x['event'] == 'vm']
+                opdict = {}
+                for op in ops:
+                    opdict[op] = opdict.get(op, 0) + 1
+                out["ops"] = opdict
+            return out
+        finally:
+            # ensure LogRecorder has been disabled
+            if recorder:
+                recorder.pop_records()
 
     def profile(self, *args, **kwargs):
         kwargs['profiling'] = True
@@ -281,41 +296,6 @@ def revert(self, data):
         self.block._cached_rlp = None
         self.block.header._cached_rlp = None
 
-# logging
-
-
-def set_logging_level(lvl=0):
-    trace_lvl_map = [
-        ':info',
-        'eth.vm.log:trace',
-        ':info,eth.vm.log:trace,eth.vm.exit:trace',
-        ':info,eth.vm.log:trace,eth.vm.op:trace,eth.vm.stack:trace',
-        ':info,eth.vm.log:trace,eth.vm.op:trace,eth.vm.stack:trace,' +
-        'eth.vm.storage:trace,eth.vm.memory:trace'
-    ]
-    configure_logging(config_string=trace_lvl_map[lvl])
-    if lvl == 0:
-        set_level(None, 'info')
-    print('Set logging level: %d' % lvl)
-
-
-def set_log_trace(logger_names=[]):
-    """
-    sets all named loggers to level 'trace'
-    attention: vm.op.* are only active if vm.op is active
-    """
-    for name in logger_names:
-        assert name in slogging.get_logger_names()
-        slogging.set_level(name, 'trace')
-
-
-def enable_logging():
-    set_logging_level(1)
-
-
-def disable_logging():
-    set_logging_level(0)
-
 
 gas_limit = 3141592
 gas_price = 1

ethereum/tests/conftest.py

@@ -1,24 +1,19 @@
 import pytest
+
 from ethereum import slogging
 
 
 CATCH_LOG_HANDLER_NAME = 'catch_log_handler'
 
 
-@pytest.mark.hookwrapper
-def pytest_runtest_setup(item):
-    """Attach pytest-catchlog's handler to `slogging`'s root logger"""
-    yield
-    caplog_handler = getattr(item, CATCH_LOG_HANDLER_NAME, None)
-    if caplog_handler and caplog_handler not in slogging.rootLogger.handlers:
-        slogging.rootLogger.addHandler(caplog_handler)
+# Connect catchlog's handler to slogging's root logger
+@pytest.hookimpl(hookwrapper=True, trylast=True)
+def pytest_runtest_call(item):
+    catchlog_handler = getattr(item, CATCH_LOG_HANDLER_NAME, None)
+    if catchlog_handler and catchlog_handler not in slogging.rootLogger.handlers:
+        slogging.rootLogger.addHandler(catchlog_handler)
 
+    _ = yield
 
-@pytest.mark.hookwrapper
-def pytest_runtest_makereport(item, call):
-    """Remove pytest-catchlog's handler from `slogging`'s root logger"""
-    if call.when == 'call':
-        caplog_handler = getattr(item, CATCH_LOG_HANDLER_NAME, None)
-        if caplog_handler and caplog_handler in slogging.rootLogger.handlers:
-            slogging.rootLogger.removeHandler(caplog_handler)
-    yield
+    if catchlog_handler and catchlog_handler in slogging.rootLogger.handlers:
+        slogging.rootLogger.removeHandler(catchlog_handler)

ethereum/tests/test_abi.py

@@ -4,31 +4,24 @@
 import ethereum.abi as abi
 logger = get_logger()
 
+
 def test_abi_encode_var_sized_array():
     abi.encode_abi(['address[]'], [[b'\x00' * 20] * 3])
 
+
 def test_abi_encode_fixed_size_array():
     abi.encode_abi(['uint16[2]'], [[5, 6]])
 
+
 def test_abi_encode_signed_int():
     assert abi.decode_abi(['int8'], abi.encode_abi(['int8'], [1]))[0] == 1
     assert abi.decode_abi(['int8'], abi.encode_abi(['int8'], [-1]))[0] == -1
 
 
-# SETUP TESTS IN GLOBAL NAME SPACE
-def gen_func(filename, testname, testdata):
-    return lambda: do_test_state(filename, testname, testdata)
-
-def do_test_state(filename, testname=None, testdata=None, limit=99999999):
-    logger.debug('running test:%r in %r' % (testname, filename))
+# Will be parametrized fron json fixtures
+def test_state(filename, testname, testdata):
     testutils.check_abi_test(testutils.fixture_to_bytes(testdata))
 
-fixtures = testutils.get_tests_from_file_or_dir(
-    os.path.join(testutils.fixture_path, 'ABITests'))
 
-filenames = sorted(list(fixtures.keys()))
-for filename in filenames:
-    tests = fixtures[filename]
-    for testname, testdata in list(tests.items()):
-        func_name = 'test_%s_%s' % (filename, testname)
-        globals()[func_name] = gen_func(filename, testname, testdata)
+def pytest_generate_tests(metafunc):
+    testutils.generate_test_params('ABITests', metafunc)

ethereum/tests/test_blocks.py

@@ -1,3 +1,5 @@
+import pytest
+
 from ethereum import blocks, utils, db
 from ethereum.exceptions import VerificationFailed, InvalidTransaction
 import rlp
@@ -106,41 +108,44 @@ def run_block_test(params, config_overrides = {}):
     env.config = old_config
 
 
-def do_test_block(filename, testname=None, testdata=None, limit=99999999):
-    print('\nrunning test:%r in %r' % (testname, filename))
+def test_block(filename, testname, testdata):
     run_block_test(testdata, {'HOMESTEAD_FORK_BLKNUM':0 if 'Homestead' in filename else 5 if 'TestNetwork' in filename else 1000000 })
 
-excludes = [('bcWalletTest.json', u'walletReorganizeOwners'),
-            ('bl10251623GO.json', u'randomBlockTest'),
-            ('bl201507071825GO.json', u'randomBlockTest')
-            ]
 
+excludes = {
+    ('bcWalletTest.json', u'walletReorganizeOwners'),
+    ('bl10251623GO.json', u'randomBlockTest'),
+    ('bl201507071825GO.json', u'randomBlockTest')
+}
 
-if __name__ == '__main__':
+
+def pytest_generate_tests(metafunc):
+    testutils.generate_test_params(
+        'BlockchainTests',
+        metafunc,
+        lambda filename, testname, _: (filename.split('/')[-1], testname) in excludes
+    )
+
+
+def main():
     assert len(sys.argv) >= 2, "Please specify file or dir name"
     fixtures = testutils.get_tests_from_file_or_dir(sys.argv[1])
     if len(sys.argv) >= 3:
         for filename, tests in list(fixtures.items()):
             for testname, testdata in list(tests.items()):
                 if testname == sys.argv[2]:
                     print("Testing: %s %s" % (filename, testname))
-                    run_block_test(testdata, {'HOMESTEAD_FORK_BLKNUM':0 if 'Homestead' in filename else 5 if 'TestNetwork' in filename else 1000000 })
+                    run_block_test(testdata, {
+                        'HOMESTEAD_FORK_BLKNUM': 0 if 'Homestead' in filename else 5 if 'TestNetwork' in filename
+                        else 1000000})
     else:
         for filename, tests in list(fixtures.items()):
             for testname, testdata in list(tests.items()):
                 if (filename.split('/')[-1], testname) not in excludes:
                     print("Testing: %s %s" % (filename, testname))
-                    run_block_test(testdata, {'HOMESTEAD_FORK_BLKNUM':0 if 'Homestead' in filename else 5 if 'TestNetwork' in filename else 1000000 })
-else:
-    fixtures = testutils.get_tests_from_file_or_dir(
-        os.path.join(testutils.fixture_path, 'BlockchainTests'))
-
-    def mk_test_func(filename, testname, testdata):
-        return lambda: do_test_block(filename, testname, testdata)
-
-    for filename, tests in list(fixtures.items()):
-        for testname, testdata in list(tests.items())[:500]:
-            func_name = 'test_%s_%s' % (filename, testname)
-            if (filename.split('/')[-1], testname) not in excludes:
-                # print 'making function', (filename.split('/')[-1], testname)
-                globals()[func_name] = mk_test_func(filename, testname, testdata)
+                    run_block_test(testdata, {
+                        'HOMESTEAD_FORK_BLKNUM': 0 if 'Homestead' in filename else 5 if 'TestNetwork' in filename else 1000000})
+
+
+if __name__ == '__main__':
+    main()

ethereum/tests/test_chain.py

@@ -10,9 +10,8 @@
 from ethereum.db import EphemDB
 from ethereum.tests.utils import new_db
 
-from ethereum.slogging import get_logger, configure_logging
+from ethereum.slogging import get_logger
 logger = get_logger()
-# configure_logging('eth.vm:trace,eth.vm.memory:info')
 
 _db = new_db()