[Tests] Improve UI entry script tests

 * Added parameter log.setup_logger to prevent output noise in unit tests

6 files changed, 193 insertions, 67 deletions

diff --git a/deluge/log.py b/deluge/log.py
index faf2a011f..35513c066 100644
--- a/deluge/log.py
+++ b/deluge/log.py
@@ -107,7 +107,7 @@ levels = {
 }
 
 
-def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
+def setup_logger(level="error", filename=None, filemode="w", logrotate=None, twisted_observer=True):
     """
     Sets up the basic logger and if `:param:filename` is set, then it will log
     to that file instead of stdout.
@@ -119,6 +119,7 @@ def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
         filemode (str): The filemode to use when opening the log file
         logrotate (int, optional): The size of the logfile in bytes when enabling
                                    log rotation (Default is None meaning disabled)
+        twisted_observer (bool): Whether to setup the custom twisted logging observer.
     """
     if logging.getLoggerClass() is not Logging:
         logging.setLoggerClass(Logging)
@@ -153,8 +154,9 @@ def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
     root_logger.addHandler(handler)
     root_logger.setLevel(level)
 
-    twisted_logging = TwistedLoggingObserver()
-    twisted_logging.start()
+    if twisted_observer:
+        twisted_logging = TwistedLoggingObserver()
+        twisted_logging.start()
 
 
 class TwistedLoggingObserver(PythonLoggingObserver):
diff --git a/deluge/tests/common.py b/deluge/tests/common.py
index ccf93fbce..61567212d 100644
--- a/deluge/tests/common.py
+++ b/deluge/tests/common.py
@@ -14,6 +14,7 @@ import deluge.log
 from deluge.error import DelugeError
 from deluge.ui.util import lang
 
+# This sets log level to critical, so use log.critical() to debug while running unit tests
 deluge.log.setup_logger("none")
 
 
@@ -27,6 +28,10 @@ def set_tmp_config_dir():
     return config_directory
 
 
+def setup_test_logger(level="info", prefix="deluge"):
+    deluge.log.setup_logger(level, filename="%s.log" % prefix, twisted_observer=False)
+
+
 def todo_test(caller):
     # If we are using the delugereporter we can set todo mark on the test
     # Without the delugereporter the todo would print a stack trace, so in
@@ -62,6 +67,28 @@ def rpath(*args):
 lang.setup_translations()
 
 
+class ReactorOverride(object):
+    """Class used to patch reactor while running unit tests
+    to avoid starting and stopping the twisted reactor
+    """
+
+    def __getattr__(self, attr):
+        if attr == "run":
+            return self._run
+        if attr == "stop":
+            return self._stop
+        return getattr(reactor, attr)
+
+    def _run(self):
+        pass
+
+    def _stop(self):
+        pass
+
+    def addReader(self, arg):  # NOQA
+        pass
+
+
 class ProcessOutputHandler(protocol.ProcessProtocol):
 
     def __init__(self, script, callbacks, logfile=None, print_stderr=True):
diff --git a/deluge/tests/test_ui_entry.py b/deluge/tests/test_ui_entry.py
index 30db2043b..a29a31be3 100644
--- a/deluge/tests/test_ui_entry.py
+++ b/deluge/tests/test_ui_entry.py
@@ -16,23 +16,36 @@ import sys
 
 import mock
 import pytest
+from twisted.internet import defer
+from twisted.logger import Logger
 
 import deluge
 import deluge.component as component
 import deluge.ui.console
+import deluge.ui.console.commands.quit
+import deluge.ui.console.main
 import deluge.ui.web.server
 from deluge.ui import ui_entry
 from deluge.ui.web.server import DelugeWeb
 
 from . import common
 from .basetest import BaseTestCase
+from .daemon_base import DaemonBase
 
-sys_stdout = sys.stdout
-DEBUG = False
+log = Logger()
+
+DEBUG_COMMAND = False
 
+sys_stdout = sys.stdout
+# To catch output to stdout/stderr while running unit tests, we patch
+# the file descriptors in sys and argparse._sys with StringFileDescriptor.
+# Regular print statements from such tests will therefore write to the
+# StringFileDescriptor object instead of the terminal.
+# To print to terminal from the tests, use: print("Message...", file=sys_stdout)
 
-class TestStdout(object):
 
+class StringFileDescriptor(object):
+    """File descriptor that writes to string buffer"""
     def __init__(self, fd):
         self.out = StringIO.StringIO()
         self.fd = fd
@@ -53,15 +66,34 @@ class UIBaseTestCase(object):
 
     def set_up(self):
         common.set_tmp_config_dir()
+        common.setup_test_logger(level="info", prefix=self.id())
         return component.start()
 
     def tear_down(self):
         return component.shutdown()
 
     def exec_command(self):
-        if DEBUG:
+        if DEBUG_COMMAND:
             print("Executing: '%s'\n" % sys.argv, file=sys_stdout)
-        self.var["start_cmd"]()
+        return self.var["start_cmd"]()
+
+
+class UIWithDaemonBaseTestCase(UIBaseTestCase, DaemonBase):
+    """Subclass for test that require a deluged daemon"""
+
+    def __init__(self):
+        UIBaseTestCase.__init__(self)
+
+    def set_up(self):
+        d = self.common_set_up()
+        common.setup_test_logger(level="info", prefix=self.id())
+        d.addCallback(self.start_core)
+        return d
+
+    def tear_down(self):
+        d = UIBaseTestCase.tear_down(self)
+        d.addCallback(self.terminate_core)
+        return d
 
 
 class DelugeEntryTestCase(BaseTestCase):
@@ -79,7 +111,7 @@ class DelugeEntryTestCase(BaseTestCase):
         config.config["default_ui"] = "console"
         config.save()
 
-        fd = TestStdout(sys.stdout)
+        fd = StringFileDescriptor(sys.stdout)
         self.patch(argparse._sys, "stdout", fd)
 
         with mock.patch("deluge.ui.console.main.ConsoleUI"):
@@ -101,7 +133,7 @@ class DelugeEntryTestCase(BaseTestCase):
     def test_start_with_log_level(self):
         _level = []
 
-        def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
+        def setup_logger(level="error", filename=None, filemode="w", logrotate=None, output_stream=sys.stdout):
             _level.append(level)
 
         self.patch(deluge.log, "setup_logger", setup_logger)
@@ -140,10 +172,10 @@ class GtkUIDelugeScriptEntryTestCase(BaseTestCase, GtkUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge", "gtk"]
 
     def set_up(self):
-        GtkUIBaseTestCase.set_up(self)
+        return GtkUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        GtkUIBaseTestCase.tear_down(self)
+        return GtkUIBaseTestCase.tear_down(self)
 
 
 @pytest.mark.gtkui
@@ -158,10 +190,10 @@ class GtkUIScriptEntryTestCase(BaseTestCase, GtkUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge-gtk"]
 
     def set_up(self):
-        GtkUIBaseTestCase.set_up(self)
+        return GtkUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        GtkUIBaseTestCase.tear_down(self)
+        return GtkUIBaseTestCase.tear_down(self)
 
 
 class DelugeWebMock(DelugeWeb):
@@ -181,7 +213,7 @@ class WebUIBaseTestCase(UIBaseTestCase):
     def test_start_web_with_log_level(self):
         _level = []
 
-        def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
+        def setup_logger(level="error", filename=None, filemode="w", logrotate=None, output_stream=sys.stdout):
             _level.append(level)
 
         self.patch(deluge.log, "setup_logger", setup_logger)
@@ -206,10 +238,10 @@ class WebUIScriptEntryTestCase(BaseTestCase, WebUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge-web", "--do-not-daemonize"]
 
     def set_up(self):
-        WebUIBaseTestCase.set_up(self)
+        return WebUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        WebUIBaseTestCase.tear_down(self)
+        return WebUIBaseTestCase.tear_down(self)
 
 
 class WebUIDelugeScriptEntryTestCase(BaseTestCase, WebUIBaseTestCase):
@@ -222,14 +254,14 @@ class WebUIDelugeScriptEntryTestCase(BaseTestCase, WebUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge", "web", "--do-not-daemonize"]
 
     def set_up(self):
-        WebUIBaseTestCase.set_up(self)
+        return WebUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        WebUIBaseTestCase.tear_down(self)
+        return WebUIBaseTestCase.tear_down(self)
 
 
 class ConsoleUIBaseTestCase(UIBaseTestCase):
-    """Implement all Console tests here"""
+    """Implement Console tests that do not require a running daemon"""
 
     def test_start_console(self):
         self.patch(sys, "argv", self.var["sys_arg_cmd"])
@@ -239,7 +271,7 @@ class ConsoleUIBaseTestCase(UIBaseTestCase):
     def test_start_console_with_log_level(self):
         _level = []
 
-        def setup_logger(level="error", filename=None, filemode="w", logrotate=None):
+        def setup_logger(level="error", filename=None, filemode="w", logrotate=None, output_stream=sys.stdout):
             _level.append(level)
 
         self.patch(deluge.log, "setup_logger", setup_logger)
@@ -257,7 +289,7 @@ class ConsoleUIBaseTestCase(UIBaseTestCase):
 
     def test_console_help(self):
         self.patch(sys, "argv", self.var["sys_arg_cmd"] + ["-h"])
-        fd = TestStdout(sys.stdout)
+        fd = StringFileDescriptor(sys.stdout)
         self.patch(argparse._sys, "stdout", fd)
 
         with mock.patch("deluge.ui.console.main.ConsoleUI"):
@@ -271,7 +303,7 @@ class ConsoleUIBaseTestCase(UIBaseTestCase):
 
     def test_console_command_info(self):
         self.patch(sys, "argv", self.var["sys_arg_cmd"] + ["info"])
-        fd = TestStdout(sys.stdout)
+        fd = StringFileDescriptor(sys.stdout)
         self.patch(argparse._sys, "stdout", fd)
 
         with mock.patch("deluge.ui.console.main.ConsoleUI"):
@@ -279,7 +311,7 @@ class ConsoleUIBaseTestCase(UIBaseTestCase):
 
     def test_console_command_info_help(self):
         self.patch(sys, "argv", self.var["sys_arg_cmd"] + ["info", "-h"])
-        fd = TestStdout(sys.stdout)
+        fd = StringFileDescriptor(sys.stdout)
         self.patch(argparse._sys, "stdout", fd)
 
         with mock.patch("deluge.ui.console.main.ConsoleUI"):
@@ -290,13 +322,72 @@ class ConsoleUIBaseTestCase(UIBaseTestCase):
 
     def test_console_unrecognized_arguments(self):
         self.patch(sys, "argv", ["./deluge", "--ui", "console"])  # --ui is not longer supported
-        fd = TestStdout(sys.stdout)
+        fd = StringFileDescriptor(sys.stdout)
         self.patch(argparse._sys, "stderr", fd)
         with mock.patch("deluge.ui.console.main.ConsoleUI"):
             self.assertRaises(exceptions.SystemExit, self.exec_command)
             self.assertTrue("unrecognized arguments: --ui" in fd.out.getvalue())
 
 
+class ConsoleUIWithDaemonBaseTestCase(UIWithDaemonBaseTestCase):
+    """Implement Console tests that require a running daemon"""
+
+    def set_up(self):
+        # Avoid calling reactor.shutdown after commands are executed by main.exec_args()
+        self.patch(deluge.ui.console.commands.quit, "reactor", common.ReactorOverride())
+        return UIWithDaemonBaseTestCase.set_up(self)
+
+    @defer.inlineCallbacks
+    def test_console_command_status(self):
+        username, password = deluge.ui.common.get_localhost_auth()
+        self.patch(sys, "argv", self.var["sys_arg_cmd"] + ["--port"] + ["58900"] + ["--username"] +
+                   [username] + ["--password"] + [password] + ["status"])
+        fd = StringFileDescriptor(sys.stdout)
+        self.patch(sys, "stdout", fd)
+        self.patch(deluge.ui.console.main, "reactor", common.ReactorOverride())
+
+        yield self.exec_command()
+
+        std_output = fd.out.getvalue()
+        status_output = """Total upload: 0.0 KiB/s
+Total download: 0.0 KiB/s
+DHT Nodes: 0
+Total torrents: 0
+ Allocating: 0
+ Checking: 0
+ Downloading: 0
+ Seeding: 0
+ Paused: 0
+ Error: 0
+ Queued: 0
+ Moving: 0
+"""
+        self.assertEqual(std_output, status_output)
+
+
+class ConsoleScriptEntryWithDaemonTestCase(BaseTestCase, ConsoleUIWithDaemonBaseTestCase):
+
+    def __init__(self, testname):
+        BaseTestCase.__init__(self, testname)
+        ConsoleUIWithDaemonBaseTestCase.__init__(self)
+        self.var["cmd_name"] = "deluge-console"
+        self.var["sys_arg_cmd"] = ["./deluge-console"]
+
+    def set_up(self):
+        from deluge.ui.console.console import Console
+
+        def start_console():
+            return Console().start()
+
+        self.patch(deluge.ui.console, "start", start_console)
+        self.var["start_cmd"] = deluge.ui.console.start
+
+        return ConsoleUIWithDaemonBaseTestCase.set_up(self)
+
+    def tear_down(self):
+        return ConsoleUIWithDaemonBaseTestCase.tear_down(self)
+
+
 class ConsoleScriptEntryTestCase(BaseTestCase, ConsoleUIBaseTestCase):
 
     def __init__(self, testname):
@@ -307,10 +398,10 @@ class ConsoleScriptEntryTestCase(BaseTestCase, ConsoleUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge-console"]
 
     def set_up(self):
-        ConsoleUIBaseTestCase.set_up(self)
+        return ConsoleUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        ConsoleUIBaseTestCase.tear_down(self)
+        return ConsoleUIBaseTestCase.tear_down(self)
 
 
 class ConsoleDelugeScriptEntryTestCase(BaseTestCase, ConsoleUIBaseTestCase):
@@ -323,7 +414,7 @@ class ConsoleDelugeScriptEntryTestCase(BaseTestCase, ConsoleUIBaseTestCase):
         self.var["sys_arg_cmd"] = ["./deluge", "console"]
 
     def set_up(self):
-        ConsoleUIBaseTestCase.set_up(self)
+        return ConsoleUIBaseTestCase.set_up(self)
 
     def tear_down(self):
-        ConsoleUIBaseTestCase.tear_down(self)
+        return ConsoleUIBaseTestCase.tear_down(self)
diff --git a/deluge/tests/test_web_api.py b/deluge/tests/test_web_api.py
index 5c56970be..08cb48b01 100644
--- a/deluge/tests/test_web_api.py
+++ b/deluge/tests/test_web_api.py
@@ -31,27 +31,11 @@ from .daemon_base import DaemonBase
 common.disable_new_release_check()
 
 
-class ReactorOverride(object):
-
-    def __getattr__(self, attr):
-        if attr == "run":
-            return self._run
-        if attr == "stop":
-            return self._stop
-        return getattr(reactor, attr)
-
-    def _run(self):
-        pass
-
-    def _stop(self):
-        pass
-
-
 class WebAPITestCase(BaseTestCase, DaemonBase):
 
     def set_up(self):
         self.host_id = None
-        deluge.ui.web.server.reactor = ReactorOverride()
+        deluge.ui.web.server.reactor = common.ReactorOverride()
         d = self.common_set_up()
         d.addCallback(self.start_core)
         d.addCallback(self.start_webapi)
diff --git a/deluge/ui/console/console.py b/deluge/ui/console/console.py
index 4c70ead0e..a58514792 100644
--- a/deluge/ui/console/console.py
+++ b/deluge/ui/console/console.py
@@ -94,10 +94,11 @@ class Console(UI):
 
         def run(options):
             try:
-                ConsoleUI(self.options, self.console_cmds)
+                c = ConsoleUI(self.options, self.console_cmds)
+                return c.start_ui()
             except Exception as ex:
                 log.exception(ex)
                 raise
 
-        deluge.common.run_profiled(run, self.options, output_file=self.options.profile,
-                                   do_profile=self.options.profile)
+        return deluge.common.run_profiled(run, self.options, output_file=self.options.profile,
+                                          do_profile=self.options.profile)
diff --git a/deluge/ui/console/main.py b/deluge/ui/console/main.py
index 732372e7e..a8ba152ee 100644
--- a/deluge/ui/console/main.py
+++ b/deluge/ui/console/main.py
@@ -219,6 +219,7 @@ class ConsoleUI(component.Component):
 
     def __init__(self, options=None, cmds=None):
         component.Component.__init__(self, "ConsoleUI", 2)
+        self.options = options
         # keep track of events for the log view
         self.events = []
         self.statusbars = None
@@ -238,36 +239,51 @@ class ConsoleUI(component.Component):
         # Set the interactive flag to indicate where we should print the output
         self.interactive = True
         self._commands = cmds
-        if options.parsed_cmds:
+        self.coreconfig = CoreConfig()
+
+    def start_ui(self):
+        """Start the console UI.
+
+        Note: When running console UI reactor.run() will be called which
+              effectively blocks this function making the return value
+              insignificant. However, when running unit tests, the reacor is
+              replaced by a mock object, leaving the return deferred object
+              necessary for the tests to run properly.
+
+        Returns:
+            Deferred: If valid commands are provided, a deferred that fires when
+                 all commands are executed. Else None is returned.
+        """
+        if self.options.parsed_cmds:
             self.interactive = False
-            if not cmds:
-                print("Sorry, couldn't find any commands")
+            if not self._commands:
+                print("No valid console commands found")
                 return
-            else:
-                self.exec_args(options)
 
-        self.coreconfig = CoreConfig()
-        if self.interactive and not deluge.common.windows_check():
-            # We use the curses.wrapper function to prevent the console from getting
-            # messed up if an uncaught exception is experienced.
-            import curses.wrapper
-            curses.wrapper(self.run)
-        elif self.interactive and deluge.common.windows_check():
-            print("""\nDeluge-console does not run in interactive mode on Windows. \n
+            deferred = self.exec_args(self.options)
+            reactor.run()
+            return deferred
+        else:
+            # Interactive
+            if deluge.common.windows_check():
+                print("""\nDeluge-console does not run in interactive mode on Windows. \n
 Please use commands from the command line, e.g.:\n
     deluge-console.exe help
     deluge-console.exe info
     deluge-console.exe "add --help"
     deluge-console.exe "add -p c:\\mytorrents c:\\new.torrent"
-            """)
-        else:
-            reactor.run()
+""")
+            else:
+                # We use the curses.wrapper function to prevent the console from getting
+                # messed up if an uncaught exception is experienced.
+                import curses.wrapper
+                curses.wrapper(self.run)
 
     def exec_args(self, options):
         commander = Commander(self._commands)
 
         def on_connect(result):
-            def on_started(result):
+            def on_components_started(result):
                 def on_started(result):
                     def do_command(result, cmd):
                         return commander.do_command(cmd)
@@ -280,11 +296,15 @@ Please use commands from the command line, e.g.:\n
                             break
                         d.addCallback(exec_command, command)
                     d.addCallback(do_command, "quit")
+                    return d
 
                 # We need to wait for the rpcs in start() to finish before processing
                 # any of the commands.
                 self.started_deferred.addCallback(on_started)
-            component.start().addCallback(on_started)
+                return self.started_deferred
+            d = component.start()
+            d.addCallback(on_components_started)
+            return d
 
         def on_connect_fail(reason):
             if reason.check(DelugeError):
@@ -303,6 +323,7 @@ Please use commands from the command line, e.g.:\n
             d = client.connect(options.daemon_addr, options.daemon_port, options.daemon_user, options.daemon_pass)
         d.addCallback(on_connect)
         d.addErrback(on_connect_fail)
+        return d
 
     def run(self, stdscr):
         """