Merge pull request #2094 from guardicore/2059-gevent-log-timestamp

2059 gevent log timestamp

monkey/monkey_island/cc/server_setup.py

@@ -28,6 +28,7 @@ from monkey_island.cc.server_utils.consts import (  # noqa: E402
 from monkey_island.cc.server_utils.island_logger import reset_logger, setup_logging  # noqa: E402
 from monkey_island.cc.services.initialize import initialize_services  # noqa: E402
 from monkey_island.cc.services.utils.network_utils import local_ip_addresses  # noqa: E402
+from monkey_island.cc.setup import PyWSGILoggingFilter  # noqa: E402
 from monkey_island.cc.setup import island_config_options_validator  # noqa: E402
 from monkey_island.cc.setup.data_dir import IncompatibleDataDirectory, setup_data_dir  # noqa: E402
 from monkey_island.cc.setup.gevent_hub_error_handler import GeventHubErrorHandler  # noqa: E402
@@ -145,13 +146,20 @@ def _start_island_server(
         app,
         certfile=config_options.crt_path,
         keyfile=config_options.key_path,
-        log=logger,
+        log=_get_wsgi_server_logger(),
         error_log=logger,
     )
     _log_init_info()
     http_server.serve_forever()
 
 
+def _get_wsgi_server_logger() -> logging.Logger:
+    wsgi_server_logger = logger.getChild("wsgi")
+    wsgi_server_logger.addFilter(PyWSGILoggingFilter())
+
+    return wsgi_server_logger
+
+
 def _log_init_info():
     logger.info("Monkey Island Server is running!")
     logger.info(f"version: {get_version()}")

monkey/monkey_island/cc/server_utils/island_logger.py

@@ -1,7 +1,7 @@
 import logging
 import logging.handlers
-import os
 import sys
+from pathlib import Path
 
 ISLAND_LOG_FILENAME = "monkey_island.log"
 LOG_FORMAT = "%(asctime)s - %(levelname)s - %(filename)s:%(lineno)s - %(funcName)s() - %(message)s"
@@ -10,19 +10,20 @@ FILE_BACKUP_COUNT = 20
 FILE_ENCODING = "utf8"
 
 
-def setup_logging(data_dir_path, log_level):
+def setup_logging(data_dir: Path, log_level: str):
     """
-    Setup the logging configuration
-    :param data_dir_path: data directory file path
-    :param log_level: level to log from
-    :return:
+    Set up the logger
+
+    :param data_dir: The data directory
+    :param log_level: A string representing threshold for the logger. Valid values are "DEBUG",
+                      "INFO", "WARNING", "ERROR", and "CRITICAL".
     """
     logger = logging.getLogger()
     logger.setLevel(log_level.upper())
 
     formatter = _get_log_formatter()
 
-    log_file_path = os.path.join(data_dir_path, ISLAND_LOG_FILENAME)
+    log_file_path = data_dir / ISLAND_LOG_FILENAME
     _add_file_handler(logger, formatter, log_file_path)
 
     _add_console_handler(logger, formatter)

monkey/monkey_island/cc/setup/__init__.py

@@ -0,0 +1 @@
+from .pywsgi_logging_filter import PyWSGILoggingFilter

monkey/monkey_island/cc/setup/pywsgi_logging_filter.py

@@ -0,0 +1,26 @@
+import re
+from logging import Filter, LogRecord
+
+
+class PyWSGILoggingFilter(Filter):
+    """
+    Remove the superfluous timestamp that gevent.pywsgi.WSGIServer inserts into its log messages
+
+    The WSGIServer.format_request() hard-codes its own log format. This filter modifies the log
+    message and removes the superfluous timestamp.
+
+    See https://github.com/guardicore/monkey/issues/2059 for more information.
+    """
+
+    TIMESTAMP_REGEX = re.compile(r"- - \[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\]")
+
+    def filter(self, record: LogRecord) -> bool:
+        """
+        Remove the superfluous timestamp in gevent.pywsgi.WSGIServer log messages
+
+        :param LogRecord: A log record to modify
+        :return: True
+        """
+
+        record.msg = PyWSGILoggingFilter.TIMESTAMP_REGEX.sub("-", record.msg)
+        return True