Merge pull request #1158 from pipermerriam/piper/allow-granular-logging-config

pipermerriam · web-flow · commit 8e437eb9aa8e · 2018-08-09T11:32:56.000-06:00
Allow granular configuration of logging
diff --git a/eth/__init__.py b/eth/__init__.py
@@ -1,7 +1,7 @@
 import pkg_resources
 import sys
 
-from eth.utils.logging import (
+from eth.tools.logging import (
     setup_trace_logging
 )
 
diff --git a/eth/db/account.py b/eth/db/account.py
@@ -42,8 +42,7 @@
     validate_uint256,
     validate_canonical_address,
 )
-
-from eth.utils.logging import (
+from eth.tools.logging import (
     TraceLogger
 )
 from eth.utils.numeric import (
diff --git a/eth/tools/logging.py b/eth/tools/logging.py
@@ -0,0 +1,16 @@
+import logging
+from typing import Any
+
+TRACE_LEVEL_NUM = 5
+
+
+class TraceLogger(logging.Logger):
+
+    def trace(self, message: str, *args: Any, **kwargs: Any) -> None:
+        self.log(TRACE_LEVEL_NUM, message, *args, **kwargs)
+
+
+def setup_trace_logging() -> None:
+    logging.setLoggerClass(TraceLogger)
+    logging.addLevelName(TRACE_LEVEL_NUM, 'TRACE')
+    setattr(logging, 'TRACE', TRACE_LEVEL_NUM)  # typing: ignore
diff --git a/eth/utils/logging.py b/eth/utils/logging.py
@@ -1,15 +0,0 @@
-import logging
-from typing import Any
-
-TRACE_LEVEL_NUM = 5
-
-
-class TraceLogger(logging.Logger):
-
-    def trace(self, message: str, *args: Any, **kwargs: Any) -> None:
-        self.log(TRACE_LEVEL_NUM, message, *args, **kwargs)
-
-
-def setup_trace_logging() -> None:
-    logging.setLoggerClass(TraceLogger)
-    logging.addLevelName(TRACE_LEVEL_NUM, 'TRACE')
diff --git a/eth/vm/computation.py b/eth/vm/computation.py
@@ -26,6 +26,9 @@
     Halt,
     VMError,
 )
+from eth.tools.logging import (
+    TraceLogger
+)
 from eth.utils.datatypes import (
     Configurable,
 )
@@ -35,9 +38,6 @@
 from eth.utils.numeric import (
     ceil32,
 )
-from eth.utils.logging import (
-    TraceLogger
-)
 from eth.validation import (
     validate_canonical_address,
     validate_is_bytes,
diff --git a/eth/vm/gas_meter.py b/eth/vm/gas_meter.py
@@ -10,7 +10,7 @@
 from eth.validation import (
     validate_uint256,
 )
-from eth.utils.logging import (
+from eth.tools.logging import (
     TraceLogger
 )
 
diff --git a/p2p/__init__.py b/p2p/__init__.py
@@ -1,2 +1,2 @@
 # This is to ensure we call setup_trace_logging() before anything else.
-import eth as eth_module  # noqa: F401
+import eth as _eth_module  # noqa: F401
diff --git a/p2p/peer.py b/p2p/peer.py
@@ -1014,9 +1014,9 @@ def _test() -> None:
     """
     import argparse
     import signal
-    from eth.utils.logging import TRACE_LEVEL_NUM
     from eth.chains.ropsten import RopstenChain, ROPSTEN_GENESIS_HEADER, ROPSTEN_VM_CONFIGURATION
     from eth.db.backends.memory import MemoryDB
+    from eth.tools.logging import TRACE_LEVEL_NUM
     from trinity.protocol.eth.peer import ETHPeer
     from trinity.protocol.eth.requests import HeaderRequest as ETHHeaderRequest
     from trinity.protocol.les.peer import LESPeer
diff --git a/p2p/service.py b/p2p/service.py
@@ -10,7 +10,7 @@
     cast,
 )
 
-from eth.utils.logging import TraceLogger
+from eth.tools.logging import TraceLogger
 
 from cancel_token import CancelToken, OperationCancelled
 
diff --git a/tests/trinity/core/cli/test_log_level_configuration.py b/tests/trinity/core/cli/test_log_level_configuration.py
@@ -0,0 +1,48 @@
+import pytest
+
+from trinity.cli_parser import (
+    parser,
+    LOG_LEVEL_CHOICES,
+)
+
+
+def test_cli_log_level_not_specified():
+    ns = parser.parse_args([])
+    assert ns.log_levels is None
+
+
+@pytest.mark.parametrize(
+    'level,expected',
+    LOG_LEVEL_CHOICES.items(),
+)
+def test_cli_log_level_global_values(level, expected):
+    ns = parser.parse_args(['--log-level', level])
+    assert ns.log_levels == {None: expected}
+
+
+@pytest.mark.parametrize(
+    'level,expected',
+    LOG_LEVEL_CHOICES.items(),
+)
+def test_cli_log_level_module_value(level, expected):
+    ns = parser.parse_args(['--log-level', "module={0}".format(level)])
+    assert ns.log_levels == {'module': expected}
+
+
+def test_cli_log_level_error_for_multiple_globals():
+    with pytest.raises(SystemExit):
+        parser.parse_args([
+            '--log-level', 'DEBUG',
+            '--log-level', 'modue=DEBUG',
+            '--log-level', 'ERROR',
+        ])
+
+
+def test_cli_log_level_error_for_repeated_name():
+    with pytest.raises(SystemExit):
+        parser.parse_args([
+            '--log-level', 'DEBUG',
+            '--log-level', 'modue_a=DEBUG',
+            '--log-level', 'modue_b=DEBUG',
+            '--log-level', 'modue_a=DEBUG',
+        ])
diff --git a/tests/trinity/core/p2p-proto/test_state_sync.py b/tests/trinity/core/p2p-proto/test_state_sync.py
@@ -16,7 +16,7 @@
 
 from eth.db.backends.memory import MemoryDB
 from eth.db.account import AccountDB
-from eth.utils.logging import TraceLogger
+from eth.tools.logging import TraceLogger
 
 from trinity.sync.full.hexary_trie import HexaryTrieSync
 from trinity.sync.full.state import StateSync, TrieNodeRequestTracker
diff --git a/tests/trinity/core/peer_helpers.py b/tests/trinity/core/peer_helpers.py
@@ -10,7 +10,7 @@
 
 from eth.chains.mainnet import MAINNET_GENESIS_HEADER
 from eth.db.backends.memory import MemoryDB
-from eth.utils.logging import TraceLogger
+from eth.tools.logging import TraceLogger
 
 from p2p import auth
 from p2p import constants
diff --git a/trinity/__init__.py b/trinity/__init__.py
@@ -9,6 +9,9 @@
         pkg_resources.get_distribution("py-evm").version,
     )
 
+# This is to ensure we call setup_trace_logging() before anything else.
+import eth as _eth_module  # noqa: F401
+
 from .main import (  # noqa: F401
     main,
 )
diff --git a/trinity/cli_parser.py b/trinity/cli_parser.py
@@ -1,4 +1,5 @@
 import argparse
+import logging
 from typing import (
     Any,
 )
@@ -9,6 +10,7 @@
 from eth.chains.ropsten import (
     ROPSTEN_NETWORK_ID,
 )
+from eth.tools.logging import TRACE_LEVEL_NUM
 
 from p2p.kademlia import Node
 
@@ -23,28 +25,102 @@ class ValidateAndStoreEnodes(argparse.Action):
     def __call__(self,
                  parser: argparse.ArgumentParser,
                  namespace: argparse.Namespace,
-                 values: Any,
+                 value: Any,
                  option_string: str=None) -> None:
-        if values is None:
+        if value is None:
             return
 
-        enode = Node.from_uri(values)
+        enode = Node.from_uri(value)
 
         if getattr(namespace, self.dest) is None:
             setattr(namespace, self.dest, [])
         enode_list = getattr(namespace, self.dest)
         enode_list.append(enode)
 
 
-DEFAULT_LOG_LEVEL = 'info'
-LOG_LEVEL_CHOICES = (
-    'trace',
-    'debug',
-    'info',
-    'warning',
-    'error',
-    'critical',
-)
+LOG_LEVEL_CHOICES = {
+    # numeric versions
+    '5': TRACE_LEVEL_NUM,
+    '10': logging.DEBUG,
+    '20': logging.INFO,
+    '30': logging.WARNING,
+    '40': logging.ERROR,
+    '50': logging.CRITICAL,
+    # string versions
+    'TRACE': TRACE_LEVEL_NUM,
+    'DEBUG': logging.DEBUG,
+    'INFO': logging.INFO,
+    'WARN': logging.WARNING,
+    'WARNING': logging.WARNING,
+    'ERROR': logging.ERROR,
+    'CRITICAL': logging.CRITICAL,
+}
+
+
+class ValidateAndStoreLogLevel(argparse.Action):
+    def __call__(self,
+                 parser: argparse.ArgumentParser,
+                 namespace: argparse.Namespace,
+                 value: Any,
+                 option_string: str=None) -> None:
+        if value is None:
+            return
+
+        raw_value = value.upper()
+
+        # this is a global log level.
+        if raw_value in LOG_LEVEL_CHOICES:
+            path = None
+            log_level = LOG_LEVEL_CHOICES[raw_value]
+        else:
+            path, _, raw_log_level = value.partition('=')
+
+            if not path or not raw_log_level:
+                raise argparse.ArgumentError(
+                    self,
+                    "Invalid logging config: '{0}'.  Log level may be specified "
+                    "as a global logging level using the syntax `--log-level "
+                    "<LEVEL-NAME>` or for to specify the logging level for an "
+                    "individual logger, '--log-level "
+                    "<LOGGER-NAME>:<LEVEL-NAME>'".format(value)
+                )
+
+            try:
+                log_level = LOG_LEVEL_CHOICES[raw_log_level.upper()]
+            except KeyError:
+                raise argparse.ArgumentError(
+                    self,
+                    (
+                        "Invalid logging level.  Got '{0}'.  Must be one of\n"
+                        " - 5/10/20/30/40 (numeric logging levels)\n"
+                        " - trace/debug/info/warn/warning/error/critical (lowercase)\n"
+                        " - TRACE/DEBUG/INFO/WARN/WARNING/ERROR/CRITICAL (uppercase)\n"
+                    ).format(raw_log_level),
+                )
+
+        if getattr(namespace, self.dest) is None:
+            setattr(namespace, self.dest, {})
+        log_levels = getattr(namespace, self.dest)
+        if path in log_levels:
+            if path is None:
+                raise argparse.ArgumentError(
+                    self,
+                    "Global logging has already been configured to '{0}'.  The "
+                    "global logging level may only be specified once.".format(
+                        log_level,
+                    )
+                )
+            else:
+                raise argparse.ArgumentError(
+                    self,
+                    "The logging level for '{0}' was provided more than once. "
+                    "Please ensure the each name is provided only once"
+                )
+        log_levels[path] = log_level
+
+
+DEFAULT_STDERR_LOG_LEVEL = logging.INFO
+DEFAULT_DEBUG_LOG_LEVEL = logging.DEBUG
 
 
 parser = argparse.ArgumentParser(description='Trinity')
@@ -95,9 +171,32 @@ def __call__(self,
 logging_parser.add_argument(
     '-l',
     '--log-level',
-    choices=LOG_LEVEL_CHOICES,
-    default=DEFAULT_LOG_LEVEL,
-    help="Sets the logging level",
+    action=ValidateAndStoreLogLevel,
+    dest="log_levels",
+    metavar="LEVEL",
+    help=(
+        "Configure the logging level. The `LEVEL` may be provide as any of: "
+        "TRACE/DEBUG/INFO/WARN/WARNING/ERROR/CRITICAL, "
+        "5/10/20/30/40/50, or to specify "
+        "the logging level for a specific logger, `--log-level "
+        "LOGGER_NAME=LEVEL`.  Default: INFO"
+    ),
+)
+logging_parser.add_argument(
+    '--stderr-log-level',
+    dest="stderr_log_level",
+    default=DEFAULT_STDERR_LOG_LEVEL,
+    help=(
+        "Configure the logging level for the stderr logging."
+    ),
+)
+logging_parser.add_argument(
+    '--file-log-level',
+    dest="file_log_level",
+    default=DEFAULT_DEBUG_LOG_LEVEL,
+    help=(
+        "Configure the logging level for file-based logging."
+    ),
 )
 
 #
diff --git a/trinity/main.py b/trinity/main.py
diff --git a/trinity/p2p/handlers.py b/trinity/p2p/handlers.py
diff --git a/trinity/sync/full/hexary_trie.py b/trinity/sync/full/hexary_trie.py
diff --git a/trinity/sync/full/state.py b/trinity/sync/full/state.py
diff --git a/trinity/utils/logging.py b/trinity/utils/logging.py

Original file line number	Diff line number	Diff line change
`@@ -1,7 +1,7 @@`
`1`	`1`	`import pkg_resources`
`2`	`2`	`import sys`
`3`	`3`
`4`		`-from eth.utils.logging import (`
	`4`	`+from eth.tools.logging import (`
`5`	`5`	`setup_trace_logging`
`6`	`6`	`)`
`7`	`7`
Original file line number	Diff line number	Diff line change
`@@ -42,8 +42,7 @@`
`42`	`42`	`validate_uint256,`
`43`	`43`	`validate_canonical_address,`
`44`	`44`	`)`
`45`		`-`
`46`		`-from eth.utils.logging import (`
	`45`	`+from eth.tools.logging import (`
`47`	`46`	`TraceLogger`
`48`	`47`	`)`
`49`	`48`	`from eth.utils.numeric import (`
Original file line number	Diff line number	Diff line change
`@@ -26,6 +26,9 @@`
`26`	`26`	`Halt,`
`27`	`27`	`VMError,`
`28`	`28`	`)`
	`29`	`+from eth.tools.logging import (`
	`30`	`+ TraceLogger`
	`31`	`+)`
`29`	`32`	`from eth.utils.datatypes import (`
`30`	`33`	`Configurable,`
`31`	`34`	`)`
`@@ -35,9 +38,6 @@`
`35`	`38`	`from eth.utils.numeric import (`
`36`	`39`	`ceil32,`
`37`	`40`	`)`
`38`		`-from eth.utils.logging import (`
`39`		`- TraceLogger`
`40`		`-)`
`41`	`41`	`from eth.validation import (`
`42`	`42`	`validate_canonical_address,`
`43`	`43`	`validate_is_bytes,`
Original file line number	Diff line number	Diff line change
`@@ -10,7 +10,7 @@`
`10`	`10`	`from eth.validation import (`
`11`	`11`	`validate_uint256,`
`12`	`12`	`)`
`13`		`-from eth.utils.logging import (`
	`13`	`+from eth.tools.logging import (`
`14`	`14`	`TraceLogger`
`15`	`15`	`)`
`16`	`16`
Original file line number	Diff line number	Diff line change
`@@ -1,2 +1,2 @@`
`1`	`1`	`# This is to ensure we call setup_trace_logging() before anything else.`
`2`		`-import eth as eth_module # noqa: F401`
	`2`	`+import eth as _eth_module # noqa: F401`