Set number level new logger as root level logger

ethereum/abi.py

@@ -2,10 +2,13 @@
 import re
 import yaml  # use yaml instead of json to get non unicode (works with ascii only data)
 from ethereum import utils
+from ethereum import slogging
 from rlp.utils import decode_hex, encode_hex
 from ethereum.utils import encode_int, zpad, big_endian_to_int, is_numeric, is_string, ceil32
+from ethereum.slogging import get_logger
 import ast
 
+log = get_logger('eth.abi')
 
 def json_decode(x):
     return yaml.safe_load(x)
@@ -105,7 +108,8 @@ def listen(self, log, noprint=False):
                 c2 += 1
         o["_event_type"] = utils.to_string(name)
         if not noprint:
-            print(o)
+            logger = slogging.getLogger()
+            log.info(o)
         return o
 
 

ethereum/blocks.py

@@ -1439,4 +1439,4 @@ def dump_genesis_block_tests_data(db):
     for addr, balance in GENESIS_INITIAL_ALLOC.items():
         data['initial_alloc'][addr] = to_string(balance)
 
-    print(json.dumps(data, indent=1))
+    log.info(json.dumps(data, indent=1))

ethereum/pruning_trie.py

@@ -5,10 +5,13 @@
 from ethereum import utils
 from ethereum.utils import to_string
 from ethereum.utils import is_string
+from ethereum.slogging import get_logger
 import copy
 from rlp.utils import decode_hex, encode_hex, ascii_chr, str_to_bytes
 import sys
 
+log = get_logger('eth.pruning_trie')
+
 bin_to_nibbles_cache = {}
 
 hti = {}
@@ -952,7 +955,7 @@ def verify_spv_proof(root, key, proof):
         proof.pop()
         return True
     except Exception as e:
-        print(e)
+        log.error(e)
         proof.pop()
         return False
 
@@ -972,7 +975,7 @@ def encode_node(nd):
         if sys.argv[1] == 'insert':
             t = Trie(_db, decode_hex(sys.argv[3]))
             t.update(sys.argv[4], sys.argv[5])
-            print(encode_node(t.root_hash))
+            log.info(encode_node(t.root_hash))
         elif sys.argv[1] == 'get':
             t = Trie(_db, decode_hex(sys.argv[3]))
-            print(t.get(sys.argv[4]))
+            log.info(t.get(sys.argv[4]))

ethereum/slogging.py

@@ -33,6 +33,10 @@ def hexprint(x):
 logging.addLevelName(TRACE, "TRACE")
 logging.TRACE = TRACE
 
+# add level DEV into logging
+DEV = 15
+logging.addLevelName(DEV, "DEV")
+logging.DEV = DEV
 
 formatter_set = frozenset(['name', 'levelno', 'levelname', 'pathname', 'filename', 'module',
     'lineno', 'funcName', 'created', 'asctime', 'msecs', 'relativeCreated', 'thread',
@@ -123,6 +127,68 @@ def wrapper(self, msg, *args, **kwargs):
         fun(self, msg, *args, **kwargs)
     return wrapper
 
+class EthLogRecord(logging.LogRecord):
+    def __init__(self, *args, **kwargs):
+        super(EthLogRecord, self).__init__(*args, **kwargs)
+
+    def getMessage(self):
+        msg = super(EthLogRecord, self).getMessage()
+        if self.levelno == logging.DEV:
+            return msg
+        else:
+            return msg
+
+try:
+    unicode
+    _unicode = True
+except NameError:
+    _unicode = False
+
+class EthStreamHandler(logging.StreamHandler):
+    def __init__(self, stream=None ):
+        super(EthStreamHandler, self).__init__(stream)
+        self.dict_colors = {}
+        self.dict_colors["HEADER"] = '\033[95m'
+        self.dict_colors["OKBLUE"] = '\033[94m'
+        self.dict_colors["OKGREEN"] = '\033[92m'
+        self.dict_colors["WARNING"] = '\033[91m'
+        self.dict_colors["FAIL"] = '\033[91m'
+        self.dict_colors["ENDC"] = '\033[0m'
+        self.dict_colors["BOLD"] = '\033[1m'
+        self.dict_colors["UNDERLINE"] = '\033[4m'
+
+    def emit(self, record):
+        """
+        Emit a record.
+        This function from standart logging module from StreamHandler with some changes
+        """
+        try:
+            msg = self.format(record)
+            if record.levelno == logging.DEV:
+                msg = self.dict_colors["FAIL"] + msg + self.dict_colors["ENDC"]
+            stream = self.stream
+            fs = "%s\n"
+            if not _unicode: #if no unicode support...
+                stream.write(fs % msg)
+            else:
+                try:
+                    if (isinstance(msg, unicode) and
+                        getattr(stream, 'encoding', None)):
+                        ufs = u'%s\n'
+                        try:
+                            stream.write(ufs % msg)
+                        except UnicodeEncodeError:
+                            stream.write((ufs % msg).encode(stream.encoding))
+                    else:
+                        stream.write(fs % msg)
+                except UnicodeError:
+                    stream.write(fs % msg.encode("UTF-8"))
+            self.flush()
+        except (KeyboardInterrupt, SystemExit):
+            raise
+        except:
+            self.handleError(record)
+
 class EthLogger(logging.Logger):
     def __init__(self, name, level=DEFAULT_LOGLEVEL):
         self.context_head = {}
@@ -229,6 +295,30 @@ def critical(self, msg, *args, **kwargs):
             new_kws, new_message = self.help_make_kws(kwargs, self.name, msg, getattr(self, "log_json", False))
             self._log(logging.CRITICAL, new_message, args, **new_kws)
 
+    @bind_decorator
+    def dev(self, msg, *args, **kwargs):
+        new_message = ""
+        if self.isEnabledFor(logging.DEV):
+            new_kws, new_message = self.help_make_kws(kwargs, self.name, msg, getattr(self, "log_json", False))
+            self._log(logging.DEV, new_message, args, **new_kws)
+
+    @bind_decorator
+    def DEV(self, msg, *args, **kwargs):
+        self.dev(msg, *args, **kwargs)
+
+    def makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=None, extra=None):
+        """
+        A factory method which can be overridden in subclasses to create
+        specialized LogRecords.
+        """
+        rv = EthLogRecord(name, level, fn, lno, msg, args, exc_info, func)
+        if extra is not None:
+            for key in extra:
+                if (key in ["message", "asctime"]) or (key in rv.__dict__):
+                    raise KeyError("Attempt to overwrite %r in LogRecord" % key)
+                rv.__dict__[key] = extra[key]
+        return rv
+
 class RootLogger(EthLogger):
     """
     A root logger is not that different to any other logger, except that
@@ -286,7 +376,11 @@ def getLogger(name=None):
     """
 
     if name:
-        ethlogger = EthLogger.manager.getLogger(name)
+        if name in rootLogger.manager.loggerDict: # is this a new logger ?
+            ethlogger = EthLogger.manager.getLogger(name)
+        else:
+            ethlogger = EthLogger.manager.getLogger(name)
+            ethlogger.setLevel(rootLogger.level) # set level as rootloger level
         ethlogger.log_json = rootLogger.log_json
         return ethlogger
     else:
@@ -298,21 +392,27 @@ def set_level(name, level):
     logger.setLevel(getattr(logging, level.upper()))
 
 def configure_loglevels(config_string, format=PRINT_FORMAT):
-    global FLAG_FISRST_CONFIGURE_LEVEL
     """
     config_string = ':debug,p2p:info,vm.op:trace'
     """
     assert ':' in config_string
+    conf_dict = {}
     for name_levels in config_string.split(','):
         name, level = name_levels.split(':')
+        conf_dict[name] = level
+
+    root_logger = getLogger()
+    root_logger.setLevel(logging._checkLevel(conf_dict[""].upper()))
+
+    for i in root_logger.manager.loggerDict:
+        if isinstance(root_logger.manager.loggerDict[i], EthLogger):
+            root_logger.manager.loggerDict[i].setLevel(root_logger.level) # set all logers level as root logger. Protection from many execute configure
+
+    for name in conf_dict:
+        level = conf_dict[name]
         assert not isinstance(level, int)
         logger = getLogger(name)
         logger.setLevel(getattr(logging, level.upper()))
-        if not len(logger.handlers):
-            ch = logging.StreamHandler()
-            formatter = logging.Formatter(format)
-            ch.setFormatter(formatter)
-            logger.addHandler(ch)
 
 def configure(config_string='', log_json=False):
     if log_json:
@@ -324,8 +424,9 @@ def configure(config_string='', log_json=False):
 
     logging.basicConfig(format=format, level=DEFAULT_LOGLEVEL) # work only first time
     ethlogger = getLogger()
+    ethlogger.DEV("------------------------ configure function ------------------------------------------")
     if not len(ethlogger.handlers):
-        ch = logging.StreamHandler()
+        ch = EthStreamHandler()
         formatter = logging.Formatter(format)
         ch.setFormatter(formatter)
         ethlogger.addHandler(ch)

ethereum/spv.py

@@ -4,7 +4,9 @@
 from ethereum import utils
 import rlp
 from ethereum import trie
+from ethereum.slogging import get_logger
 
+log = get_logger('eth.spv')
 
 def mk_transaction_spv_proof(block, tx):
     trie.proof.push(trie.RECORDING)
@@ -22,7 +24,7 @@ def verify_transaction_spv_proof(block, tx, proof):
         trie.proof.pop()
         return True
     except Exception as e:
-        print(e)
+        log.error(e)
         trie.proof.pop()
         return False
 
@@ -42,7 +44,7 @@ def mk_independent_transaction_spv_proof(block, index):
     if index > 0:
         nodes.extend(block.transactions.produce_spv_proof(rlp.encode(utils.encode_int(index - 1))))
     nodes = list(map(rlp.decode, list(set(map(rlp.encode, nodes)))))
-    print(nodes)
+    log.info(nodes)
     return rlp.encode([utils.encode_int(64), block.get_parent().list_header(),
                        block.list_header(), utils.encode_int(index), nodes])
 

ethereum/tests/test_logging.py

@@ -57,7 +57,6 @@ def test_testhandler():
     assert th.does_log(log.warn)
     assert not th.does_log(log.debug)
 
-
 def test_baseconfig():
     # test default loglevel INFO
     th = setup_logging()
@@ -72,6 +71,54 @@ def test_baseconfig():
     config_string = ':inFO,a:trace,a.b:debug'
     th = setup_logging(config_string=config_string)
 
+def test_baseconfig2():
+    # test loglevels
+    th = setup_logging(':info,p2p.discovery:debug,p2p.peer:debug,p2p:warn,eth:debug,eth.chain.tx:info')
+    root = slogging.get_logger()
+    assert th.does_log(root.error)
+    assert th.does_log(root.info)
+    assert not th.does_log(root.debug)
+    p2p_discovery = slogging.get_logger('p2p.discovery')
+    assert th.does_log(p2p_discovery.error)
+    assert th.does_log(p2p_discovery.info)
+    assert th.does_log(p2p_discovery.debug)
+    p2p_peer = slogging.get_logger('p2p.peer')
+    assert th.does_log(p2p_peer.error)
+    assert th.does_log(p2p_peer.info)
+    assert th.does_log(p2p_peer.debug)
+    p2p = slogging.get_logger('p2p')
+    assert th.does_log(p2p.error)
+    assert th.does_log(p2p.warn)
+    assert th.does_log(p2p.warning)
+    assert not th.does_log(p2p.info)
+    assert not th.does_log(p2p.debug)
+    eth = slogging.get_logger('eth')
+    assert th.does_log(eth.error)
+    assert th.does_log(eth.warn)
+    assert th.does_log(eth.warning)
+    assert th.does_log(eth.info)
+    assert th.does_log(eth.debug)
+    eth_chain_tx = slogging.get_logger('eth.chain.tx')
+    assert th.does_log(eth_chain_tx.error)
+    assert th.does_log(eth_chain_tx.warn)
+    assert th.does_log(eth_chain_tx.warning)
+    assert th.does_log(eth_chain_tx.info)
+    assert not th.does_log(eth_chain_tx.debug)
+
+    #---------------- configure again ------------------
+    th = setup_logging(':error')
+    assert th.does_log(root.error)
+    assert not th.does_log(root.info)
+    p2p_discovery = slogging.get_logger('p2p.discovery')
+    assert th.does_log(p2p_discovery.error)
+    assert not th.does_log(p2p_discovery.debug)
+    p2p_peer = slogging.get_logger('p2p.peer')
+    assert th.does_log(p2p_peer.error)
+    assert not th.does_log(p2p_peer.info)
+    p2p = slogging.get_logger('p2p')
+    assert th.does_log(p2p.error)
+    assert not th.does_log(p2p.warn)
+
 
 def test_is_active2():
     setup_logging(':info')
@@ -478,16 +525,29 @@ def test_count_logging_handlers():
     # check named logger
     eth_logger = slogging.getLogger('eth')
     slogging.configure(config_string1)
-    assert len(eth_logger.handlers) == 1
+    assert len(eth_logger.handlers) == 0
     slogging.configure(config_string1)
-    assert len(eth_logger.handlers) == 1
+    assert len(eth_logger.handlers) == 0
 
     # check child of named logger
     eth_vm_logger = slogging.getLogger('eth.vm')
     slogging.configure(config_string2)
-    assert len(eth_vm_logger.handlers) == 1
+    assert len(eth_vm_logger.handlers) == 0
     slogging.configure(config_string2)
-    assert len(eth_vm_logger.handlers) == 1
+    assert len(eth_vm_logger.handlers) == 0
+
+def mytest():
+    th = setup_logging(config_string=":debug")
+    #rl.info("this is info %s %s", 'hi', 'hellow')
+    from ethereum.utils import debug
+
+    @debug("debug_test")
+    def debug_test():
+        pass
+
+    debug_test()
+
+    assert "debug_test" in th.logged
 
 if __name__ == '__main__':
-    pass
+    mytest()

ethereum/trie.py

@@ -5,9 +5,12 @@
 from ethereum import utils
 from ethereum.utils import to_string
 from ethereum.abi import is_string
+from ethereum.slogging import get_logger
 import copy
 from rlp.utils import decode_hex, encode_hex, ascii_chr, str_to_bytes
 
+log = get_logger('eth.trie')
+
 bin_to_nibbles_cache = {}
 
 hti = {}
@@ -880,7 +883,7 @@ def verify_spv_proof(root, key, proof):
         proof.pop()
         return True
     except Exception as e:
-        print(e)
+        log.error(e)
         proof.pop()
         return False
 
@@ -901,7 +904,7 @@ def encode_node(nd):
         if sys.argv[1] == 'insert':
             t = Trie(_db, decode_hex(sys.argv[3]))
             t.update(sys.argv[4], sys.argv[5])
-            print(encode_node(t.root_hash))
+            log.info(encode_node(t.root_hash))
         elif sys.argv[1] == 'get':
             t = Trie(_db, decode_hex(sys.argv[3]))
-            print(t.get(sys.argv[4]))
+            log.info(t.get(sys.argv[4]))