Fix/rm escs in log (#54)

Author: Juliya Smith

src/code42cli/logger.py

@@ -1,6 +1,7 @@
 import logging, sys, traceback
 from logging.handlers import RotatingFileHandler
 from threading import Lock
+import copy
 
 from code42cli.compat import str
 from code42cli.util import get_user_project_path, is_interactive
@@ -79,6 +80,20 @@ def _get_user_error_logger():
         return _get_error_file_logger()
 
 
+class RedStderrHandler(logging.StreamHandler):
+    """Logging handler for logging error messages to stderr using red scary text prefixed by the 
+    word `ERROR`. For logging info to stderr, it will not add the scary red text."""
+    def __init__(self):
+        super(RedStderrHandler, self).__init__(sys.stderr)
+
+    def emit(self, record):
+        if record.levelno == logging.ERROR:
+            message = _get_red_error_text(record.msg)
+            record = copy.copy(record)
+            record.msg = message
+        super(RedStderrHandler, self).emit(record)
+
+
 def _get_interactive_user_error_logger():
     """This logger has two handlers, one for stderr and one for the error log file."""
     logger = logging.getLogger(u"code42_stderr_main")
@@ -87,7 +102,7 @@ def _get_interactive_user_error_logger():
 
     with logger_deps_lock:
         if not logger_has_handlers(logger):
-            stderr_handler = logging.StreamHandler(sys.stderr)
+            stderr_handler = RedStderrHandler()
             stderr_formatter = _get_standard_formatter()
             stderr_handler.setFormatter(stderr_formatter)
 
@@ -98,7 +113,7 @@ def _get_interactive_user_error_logger():
             add_handler_to_logger(logger, stderr_handler, stderr_formatter)
             add_handler_to_logger(logger, file_handler, file_formatter)
 
-            logger.setLevel(logging.ERROR)
+            logger.setLevel(logging.INFO)
             return logger
     return logger
 
@@ -139,14 +154,12 @@ def print_bold(self, message):
         self._info_logger.info(u"\033[1m{}\033[0m".format(message))
 
     def print_and_log_error(self, message):
-        """For not interrupting stdout output. Excludes red text and 'ERROR: ' from `error()`.
-        """
-        """Logs red text to stderr and a log file."""
-        self._user_error_logger.error(_get_red_error_text(message))
+        """Logs red error text to stderr and non-color messages to the log file."""
+        self._user_error_logger.error(message)
 
     def print_and_log_info(self, message):
-        """Logs red text to stderr and a log file."""
-        self._user_error_logger.error(message)
+        """Prints to stderr and the log file."""
+        self._user_error_logger.info(message)
 
     def log_error(self, err):
         if err:
@@ -171,7 +184,7 @@ def log_verbose_error(self, invocation_str=None, http_request=None):
         prefix = (
             u"Exception occurred."
             if not invocation_str
-            else "Exception occurred from input: '{}'.".format(invocation_str)
+            else u"Exception occurred from input: '{}'.".format(invocation_str)
         )
         message = u"{}. See error below.".format(prefix)
         self.log_error(message)

tests/cmds/detectionlists/test_init.py

@@ -36,7 +36,7 @@ def test_get_user_id_when_user_does_not_exist_logs_error(sdk_without_user, caplo
         try:
             get_user_id(sdk_without_user, "risky employee")
         except UserDoesNotExistError:
-            assert "ERROR: User 'risky employee' does not exist." in caplog.text
+            assert "User 'risky employee' does not exist." in caplog.text
 
 
 def test_update_user_adds_cloud_alias(sdk_with_user, profile):

tests/test_logger.py

@@ -1,10 +1,12 @@
 import logging
+from logging.handlers import RotatingFileHandler
 from requests import Request
 
 from code42cli.logger import (
     add_handler_to_logger,
     logger_has_handlers,
     get_view_exceptions_location_message,
+    RedStderrHandler,
     CliLogger,
 )
 from code42cli.util import get_user_project_path
@@ -39,10 +41,42 @@ def test_get_view_exceptions_location_message_returns_expected_message():
     assert actual == expected
 
 
+class TestRedStderrHandler(object):
+    def test_emit_when_error_adds_red_text(self, mocker, caplog):
+        handler = RedStderrHandler()
+        record = mocker.MagicMock(spec=logging.LogRecord)
+        record.msg = "TEST"
+        record.levelno = logging.ERROR
+
+        logger = mocker.patch("logging.StreamHandler.emit")
+        handler.emit(record)
+        actual = logger.call_args[0][0].msg
+        assert actual == "\x1b[91mERROR: TEST\x1b[0m"
+
+    def test_emit_when_info_does_not_alter(self, mocker, caplog):
+        handler = RedStderrHandler()
+        record = mocker.MagicMock(spec=logging.LogRecord)
+        record.msg = "TEST"
+        record.levelno = logging.INFO
+
+        logger = mocker.patch("logging.StreamHandler.emit")
+        handler.emit(record)
+        actual = logger.call_args[0][0].msg
+        assert actual == "TEST"
+
+
 class TestCliLogger(object):
 
     _logger = CliLogger()
 
+    def test_init_creates_user_error_logger_with_expected_handlers(self, mocker):
+        is_interactive = mocker.patch("code42cli.logger.is_interactive")
+        is_interactive.return_value = True
+        logger = CliLogger()
+        handler_types = [type(h) for h in logger._user_error_logger.handlers]
+        assert RedStderrHandler in handler_types
+        assert RotatingFileHandler in handler_types
+
     def test_print_info_logs_expected_text_at_expected_level(self, caplog):
         with caplog.at_level(logging.INFO):
             self._logger.print_info("TEST")
@@ -59,7 +93,7 @@ def test_print_and_log_error_logs_expected_text_at_expected_level(self, caplog):
             assert "TEST" in caplog.text
 
     def test_print_and_log_info_logs_expected_text_at_expected_level(self, caplog):
-        with caplog.at_level(logging.ERROR):
+        with caplog.at_level(logging.INFO):
             self._logger.print_and_log_info("TEST")
             assert "TEST" in caplog.text