Fix logging bug

lbry/lbry/extras/cli.py

@@ -8,6 +8,7 @@ import argparse
 import logging
 import logging.handlers
 from docopt import docopt
+from types import ModuleType
 
 import aiohttp
 from aiohttp.web import GracefulExit
@@ -18,7 +19,6 @@ from lbry.conf import Config, CLIConfig
 from lbry.extras.daemon.Daemon import Daemon
 
 log = logging.getLogger('lbry')
-log.addHandler(logging.NullHandler())
 
 
 def display(data):
@@ -221,38 +221,40 @@ def ensure_directory_exists(path: str):
         pathlib.Path(path).mkdir(parents=True, exist_ok=True)
 
 
-def setup_logging(args: argparse.Namespace, conf: Config, loop: asyncio.AbstractEventLoop):
+def setup_logging(args: argparse.Namespace, conf: Config, loop: asyncio.AbstractEventLoop,
+                  logging: ModuleType = logging):
     default_formatter = logging.Formatter("%(asctime)s %(levelname)-8s %(name)s:%(lineno)d: %(message)s")
     file_handler = logging.handlers.RotatingFileHandler(
         conf.log_file_path, maxBytes=2097152, backupCount=5
     )
     file_handler.setFormatter(default_formatter)
-    log.addHandler(file_handler)
+    logging.getLogger('lbry').addHandler(file_handler)
+    logging.getLogger('lbry').addHandler(logging.NullHandler())
     logging.getLogger('torba').addHandler(file_handler)
 
     if not args.quiet:
         handler = logging.StreamHandler()
         handler.setFormatter(default_formatter)
-        log.addHandler(handler)
+        logging.getLogger('lbry').addHandler(handler)
         logging.getLogger('torba').addHandler(handler)
         logging.getLogger('torba').setLevel(logging.INFO)
 
     logging.getLogger('aioupnp').setLevel(logging.WARNING)
     logging.getLogger('aiohttp').setLevel(logging.CRITICAL)
 
-    log.setLevel(logging.INFO)
+    logging.getLogger('lbry').setLevel(logging.INFO)
     if args.verbose is not None:
         loop.set_debug(True)
         if len(args.verbose) > 0:
             for module in args.verbose:
                 logging.getLogger(module).setLevel(logging.DEBUG)
         else:
-            log.setLevel(logging.DEBUG)
+            logging.getLogger('lbry').setLevel(logging.DEBUG)
 
     if conf.share_usage_data:
         loggly_handler = get_loggly_handler()
         loggly_handler.setLevel(logging.ERROR)
-        log.addHandler(loggly_handler)
+        logging.getLogger('lbry').addHandler(loggly_handler)
 
 
 def run_daemon(args: argparse.Namespace, conf: Config):

lbry/tests/integration/test_cli.py

@@ -1,6 +1,4 @@
 import contextlib
-import asyncio
-import logging
 from io import StringIO
 from torba.testcase import AsyncioTestCase
 
@@ -13,7 +11,6 @@ from lbry.extras.daemon.Components import (
 )
 from lbry.extras.daemon.Daemon import Daemon
 
-
 class CLIIntegrationTest(AsyncioTestCase):
 
     async def asyncSetUp(self):
@@ -38,28 +35,4 @@ class CLIIntegrationTest(AsyncioTestCase):
         with contextlib.redirect_stdout(actual_output):
             cli.main(["--api", "localhost:5299", "status"])
         actual_output = actual_output.getvalue()
-        self.assertIn("connection_status", actual_output)
-
-    def test_setup_logging(self):
-        def setup(argv):
-            parser = cli.get_argument_parser()
-            args, command_args = parser.parse_known_args(argv)
-            loop = asyncio.get_event_loop()
-            conf = Config.create_from_arguments(args)
-            cli.setup_logging(args, conf, loop)
-
-        setup(["start"])
-        self.assertTrue(logging.getLogger("lbry").isEnabledFor(logging.INFO))
-        self.assertFalse(logging.getLogger("lbry").isEnabledFor(logging.DEBUG))
-
-        setup(["start", "--verbose"])
-        self.assertTrue(logging.getLogger("lbry").isEnabledFor(logging.DEBUG))
-        self.assertTrue(logging.getLogger("lbry").isEnabledFor(logging.INFO))
-        self.assertFalse(logging.getLogger("torba").isEnabledFor(logging.DEBUG))
-
-        setup(["start", "--verbose", "lbry.extras", "lbry.wallet", "torba.client"])
-        self.assertTrue(logging.getLogger("lbry.extras").isEnabledFor(logging.DEBUG))
-        self.assertTrue(logging.getLogger("lbry.wallet").isEnabledFor(logging.DEBUG))
-        self.assertTrue(logging.getLogger("torba.client").isEnabledFor(logging.DEBUG))
-        self.assertFalse(logging.getLogger("lbry").isEnabledFor(logging.DEBUG))
-        self.assertFalse(logging.getLogger("torba").isEnabledFor(logging.DEBUG))
+        self.assertIn("connection_status", actual_output)

lbry/tests/unit/test_cli.py

@@ -1,13 +1,58 @@
 import contextlib
+import asyncio
+import importlib
 from io import StringIO
 from unittest import TestCase
 
 import docopt
 from torba.testcase import AsyncioTestCase
 
-from lbry.extras.cli import normalize_value, main
+from lbry.extras.cli import normalize_value, main, setup_logging
 from lbry.extras.system_info import get_platform
 from lbry.extras.daemon.Daemon import Daemon
+from lbry.conf import Config
+from lbry.extras import cli
+
+
+class CLILoggingTest(AsyncioTestCase):
+
+    async def asyncSetUp(self):
+        def import_module(name):
+            spec = importlib.util.find_spec(name)
+            module = importlib.util.module_from_spec(spec)
+            spec.loader.exec_module(module)
+            return module
+        
+        self.test_loop = asyncio.new_event_loop()
+        asyncio.set_event_loop(self.test_loop)
+
+        self.logging = import_module('logging')
+        handlers = import_module('logging.handlers')
+        self.logging.handlers = handlers
+
+    def test_setup_logging(self):
+        def setup(argv):
+            parser = cli.get_argument_parser()
+            args, command_args = parser.parse_known_args(argv)
+            conf = Config.create_from_arguments(args)
+            conf.data_dir = '/tmp'
+            setup_logging(args, conf, self.test_loop, self.logging)
+
+        setup(["start"])
+        self.assertTrue(self.logging.getLogger("lbry").isEnabledFor(self.logging.INFO))
+        self.assertFalse(self.logging.getLogger("lbry").isEnabledFor(self.logging.DEBUG))
+
+        setup(["start", "--verbose"])
+        self.assertTrue(self.logging.getLogger("lbry").isEnabledFor(self.logging.DEBUG))
+        self.assertTrue(self.logging.getLogger("lbry").isEnabledFor(self.logging.INFO))
+        self.assertFalse(self.logging.getLogger("torba").isEnabledFor(self.logging.DEBUG))
+
+        setup(["start", "--verbose", "lbry.extras", "lbry.wallet", "torba.client"])
+        self.assertTrue(self.logging.getLogger("lbry.extras").isEnabledFor(self.logging.DEBUG))
+        self.assertTrue(self.logging.getLogger("lbry.wallet").isEnabledFor(self.logging.DEBUG))
+        self.assertTrue(self.logging.getLogger("torba.client").isEnabledFor(self.logging.DEBUG))
+        self.assertFalse(self.logging.getLogger("lbry").isEnabledFor(self.logging.DEBUG))
+        self.assertFalse(self.logging.getLogger("torba").isEnabledFor(self.logging.DEBUG))
 
 
 class CLITest(AsyncioTestCase):