Merge pull request #275 from solarwinds/NH-69396-fix-logname-usage

NH-69396 Update usage of SW_APM_LOG_FILEPATH

solarwinds_apm/apm_config.py

@@ -97,7 +97,7 @@ def __init__(
             "reporter": "",  # the reporter mode, either 'udp' or 'ssl'.
             "log_type": apm_logging.ApmLoggingType.default_type(),
             "debug_level": apm_logging.ApmLoggingLevel.default_level(),
-            "logname": "",
+            "log_filepath": "",
             "service_key": "",
             "hostname_alias": "",
             "trustedpath": "",
@@ -135,10 +135,17 @@ def __init__(
             self.__config["service_key"],
             self.service_name,
         )
-        self.update_log_type()
-        # update logging level of Python logging logger
+
+        # Update and apply logging settings to Python logger
+        self.update_log_settings()
+        apm_logging.set_sw_log_type(
+            self.__config["log_type"],
+            self.__config["log_filepath"],
+        )
         apm_logging.set_sw_log_level(self.__config["debug_level"])
 
+        self.update_log_filepath_for_reporter()
+
         # Calculate c-lib extension usage
         (
             self.extension,
@@ -463,21 +470,65 @@ def _update_service_key_name(
         # Else no need to update service_key when not reporting
         return service_key
 
+    def update_log_settings(
+        self,
+    ) -> None:
+        """Update log_filepath and log type"""
+        self.update_log_filepath()
+        self.update_log_type()
+
+    def update_log_filepath(
+        self,
+    ) -> None:
+        """Checks SW_APM_LOG_FILEPATH path to file else fileHandler will fail.
+        If invalid, create path to match Boost.log behaviour.
+        If not possible, switch to default log settings.
+        """
+        log_filepath = os.path.dirname(self.__config["log_filepath"])
+        if log_filepath:
+            if not os.path.exists(log_filepath):
+                try:
+                    os.makedirs(log_filepath)
+                    logger.debug(
+                        "Created directory path from provided SW_APM_LOG_FILEPATH."
+                    )
+                except FileNotFoundError:
+                    logger.error(
+                        "Could not create log file directory path from provided SW_APM_LOG_FILEPATH. Using default log settings."
+                    )
+                    self.__config["log_filepath"] = ""
+                    self.__config[
+                        "log_type"
+                    ] = apm_logging.ApmLoggingType.default_type()
+
     def update_log_type(
         self,
     ) -> None:
         """Updates agent log type depending on other configs.
 
         SW_APM_DEBUG_LEVEL -1 will set c-lib log_type to disabled (4).
-        SW_APM_LOGNAME not None will set c-lib log_type to file (2).
+        SW_APM_LOG_FILEPATH not None will set c-lib log_type to file (2).
         """
         if self.__config["debug_level"] == -1:
             self.__config[
                 "log_type"
             ] = apm_logging.ApmLoggingType.disabled_type()
-        elif self.__config["logname"]:
+        elif self.__config["log_filepath"]:
             self.__config["log_type"] = apm_logging.ApmLoggingType.file_type()
 
+    def update_log_filepath_for_reporter(
+        self,
+    ) -> None:
+        """Updates log_filepath for extension Reporter to avoid conflict"""
+        orig_log_filepath = self.__config["log_filepath"]
+        if orig_log_filepath:
+            log_filepath, log_filepath_ext = os.path.splitext(
+                orig_log_filepath
+            )
+            self.__config[
+                "log_filepath"
+            ] = f"{log_filepath}_ext{log_filepath_ext}"
+
     def _calculate_metric_format(self) -> int:
         """Return one of 1 (TransactionResponseTime only) or 2 (default; ResponseTime only). Note: 0 (both) is no longer supported. Based on collector URL which may have a port e.g. foo-collector.com:443"""
         metric_format = 2

solarwinds_apm/apm_logging.py

@@ -36,6 +36,7 @@
 
 import logging
 import os
+from logging.handlers import RotatingFileHandler
 
 
 class ApmLoggingType:
@@ -188,6 +189,41 @@ def disable_logger(disable=True):
         logger.propagate = True
 
 
+def set_sw_log_type(log_type, log_filepath=""):
+    """Set the logging 'type' of the agent-internal logger.
+
+    This function expects the log_type to be one of the integer
+    representations of the levels defined in ApmLoggingType.log_types.
+    If an invalid type has been provided, the logging handler will not be
+    changed but a warning message will be emitted.
+
+    If log_filepath is provided and log_type is file_type, logger stream handler
+    is swapped with a rotating file handler.
+    """
+    if not ApmLoggingType.is_valid_log_type(log_type):
+        logger.warning(
+            "set_sw_log_type: Ignore attempt to set solarwinds_apm logger with invalid logging handler."
+        )
+        return
+
+    if log_type == ApmLoggingType.file_type() and log_filepath:
+        try:
+            # no rollover to match oboe logs
+            file_hander = RotatingFileHandler(
+                filename=log_filepath,
+                maxBytes=0,
+                backupCount=0,
+            )
+            logger.addHandler(file_hander)
+            # stop logging to stream
+            logger.removeHandler(_stream_handler)
+        except FileNotFoundError:
+            # path should be checked first by ApmConfig.update_log_filepath
+            logger.error(
+                "Could not write logs to file; please check configured SW_APM_LOG_FILEPATH."
+            )
+
+
 def set_sw_log_level(level):
     """Set the logging level of the agent-internal logger to the provided level. This function expects the level
     to be one of the integer representations of the levels defined in ApmLoggingLevel.debug_levels.

solarwinds_apm/configurator.py

@@ -465,7 +465,7 @@ def _initialize_solarwinds_reporter(
             "hostname_alias": apm_config.get("hostname_alias"),
             "log_type": apm_config.get("log_type"),
             "log_level": apm_config.get("debug_level"),
-            "log_file_path": apm_config.get("logname"),
+            "log_file_path": apm_config.get("log_filepath"),
             "max_transactions": apm_config.get("max_transactions"),
             "max_flush_wait_time": apm_config.get("max_flush_wait_time"),
             "events_flush_interval": apm_config.get("events_flush_interval"),

tests/unit/test_apm_config/fixtures/cnf_dict.py

@@ -9,7 +9,7 @@ def fixture_cnf_dict():
         "collector": "foo-bar",
         "reporter": "udp",
         "debugLevel": 6,
-        "logname": "foo-bar",
+        "logFilepath": "foo-bar",
         "serviceKey": "not-good-to-put-here:still-could-be-used",
         "hostnameAlias": "foo-bar",
         "trustedpath": "foo-bar",
@@ -37,7 +37,7 @@ def fixture_cnf_dict_enabled_false():
         "collector": "foo-bar",
         "reporter": "udp",
         "debugLevel": 6,
-        "logname": "foo-bar",
+        "logFilepath": "foo-bar",
         "serviceKey": "not-good-to-put-here:still-could-be-used",
         "hostnameAlias": "foo-bar",
         "trustedpath": "foo-bar",
@@ -65,7 +65,7 @@ def fixture_cnf_dict_enabled_false_mixed_case():
         "collector": "foo-bar",
         "reporter": "udp",
         "debugLevel": 6,
-        "logname": "foo-bar",
+        "logFilepath": "foo-bar",
         "serviceKey": "not-good-to-put-here:still-could-be-used",
         "hostnameAlias": "foo-bar",
         "trustedpath": "foo-bar",

tests/unit/test_apm_config/test_apm_config.py

@@ -297,6 +297,9 @@ def test__init_oboe_api_and_options_configured_valid(self, mocker):
                 mock_oboe_api_options_swig,
             )
         )
+        mocker.patch(
+            "solarwinds_apm.apm_config.SolarWindsApmConfig.update_log_settings"
+        )
 
         apm_config.SolarWindsApmConfig()
         mock_oboe_api_options_swig.assert_called_once()
@@ -763,45 +766,149 @@ def test__update_service_key_name_agent_enabled_and_service_name_ok(self):
         )
         assert result == "valid_key_with:bar-service"
 
+    def test_update_log_settings(self, mocker):
+        mock_log_filepath = mocker.patch(
+            "solarwinds_apm.apm_config.SolarWindsApmConfig.update_log_filepath"
+        )
+        mock_log_type = mocker.patch(
+            "solarwinds_apm.apm_config.SolarWindsApmConfig.update_log_type"
+        )
+        # init includes update_log_settings()
+        apm_config.SolarWindsApmConfig()
+        mock_log_filepath.assert_called_once()
+        mock_log_type.assert_called_once()
+
+    def test_update_log_filepath_none(self, mocker):
+        mock_exists = mocker.patch("solarwinds_apm.apm_config.os.path.exists")
+        mock_makedirs = mocker.patch("solarwinds_apm.apm_config.os.makedirs")
+
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "")
+        test_config._set_config_value("log_type", 2)
+        test_config.update_log_filepath()
+        mock_exists.assert_not_called()
+        mock_makedirs.assert_not_called()
+        assert test_config.get("log_filepath") == ""
+        assert test_config.get("log_type") == 2
+
+    def test_update_log_filepath_no_parent_path(self, mocker):
+        mock_exists = mocker.patch("solarwinds_apm.apm_config.os.path.exists")
+        mock_makedirs = mocker.patch("solarwinds_apm.apm_config.os.makedirs")
+
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "foo")
+        test_config._set_config_value("log_type", 2)
+        test_config.update_log_filepath()
+        mock_exists.assert_not_called()
+        mock_makedirs.assert_not_called()
+        assert test_config.get("log_filepath") == "foo"
+        assert test_config.get("log_type") == 2
+
+    def test_update_log_filepath_path_exists(self, mocker):
+        mock_exists = mocker.patch("solarwinds_apm.apm_config.os.path.exists", return_value=True)
+        mock_makedirs = mocker.patch("solarwinds_apm.apm_config.os.makedirs")
+
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo")
+        test_config._set_config_value("log_type", 2)
+        test_config.update_log_filepath()
+        mock_exists.assert_called_once_with("/path/to")
+        mock_makedirs.assert_not_called()
+        assert test_config.get("log_filepath") == "/path/to/foo"
+        assert test_config.get("log_type") == 2
+
+    def test_update_log_filepath_create_path(self, mocker):
+        mock_exists = mocker.patch("solarwinds_apm.apm_config.os.path.exists", return_value=False)
+        mock_makedirs = mocker.patch("solarwinds_apm.apm_config.os.makedirs")
+
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo")
+        test_config._set_config_value("log_type", 2)
+        test_config.update_log_filepath()
+        mock_exists.assert_called_once_with("/path/to")
+        mock_makedirs.assert_called_once_with("/path/to")
+        assert test_config.get("log_filepath") == "/path/to/foo"
+        assert test_config.get("log_type") == 2
+
+    def test_update_log_filepath_cannot_create_reset_settings(self, mocker):
+        mock_exists = mocker.patch("solarwinds_apm.apm_config.os.path.exists", return_value=False)
+        mock_makedirs = mocker.patch(
+            "solarwinds_apm.apm_config.os.makedirs",
+            side_effect=FileNotFoundError("mock error")
+        )
+
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo")
+        test_config._set_config_value("log_type", 2)
+        test_config.update_log_filepath()
+        mock_exists.assert_called_once_with("/path/to")
+        mock_makedirs.assert_called_once_with("/path/to")
+        assert test_config.get("log_filepath") == ""
+        assert test_config.get("log_type") == 0
+
     def test_update_log_type_no_change(self):
         test_config = apm_config.SolarWindsApmConfig()
         test_config._set_config_value("debug_level", 2)
         test_config._set_config_value("log_type", 0)
-        test_config._set_config_value("logname", "")
+        test_config._set_config_value("log_filepath", "")
         test_config.update_log_type()
         assert test_config.get("debug_level") == 2
         assert test_config.get("log_type") == 0
-        assert test_config.get("logname") == ""
+        assert test_config.get("log_filepath") == ""
 
     def test_update_log_type_disabled(self):        
         test_config = apm_config.SolarWindsApmConfig()
         test_config._set_config_value("debug_level", -1)
         test_config._set_config_value("log_type", 0)
-        test_config._set_config_value("logname", "")
+        test_config._set_config_value("log_filepath", "")
         test_config.update_log_type()
         assert test_config.get("debug_level") == -1
         assert test_config.get("log_type") == 4
-        assert test_config.get("logname") == ""
+        assert test_config.get("log_filepath") == ""
 
-    def test_update_log_type_logname(self):
+    def test_update_log_type_log_filepath(self):
         test_config = apm_config.SolarWindsApmConfig()
         test_config._set_config_value("debug_level", 1)
         test_config._set_config_value("log_type", 0)
-        test_config._set_config_value("logname", "some-file-path")
+        test_config._set_config_value("log_filepath", "some-file-path")
         test_config.update_log_type()
         assert test_config.get("debug_level") == 1
         assert test_config.get("log_type") == 2
-        assert test_config.get("logname") == "some-file-path"
+        assert test_config.get("log_filepath") == "some-file-path"
 
-    def test_update_log_type_logname_but_disabled(self):
+    def test_update_log_type_log_filepath_but_disabled(self):
         test_config = apm_config.SolarWindsApmConfig()
         test_config._set_config_value("debug_level", -1)
         test_config._set_config_value("log_type", 0)
-        test_config._set_config_value("logname", "some-file-path")
+        test_config._set_config_value("log_filepath", "some-file-path")
         test_config.update_log_type()
         assert test_config.get("debug_level") == -1
         assert test_config.get("log_type") == 4
-        assert test_config.get("logname") == "some-file-path"
+        assert test_config.get("log_filepath") == "some-file-path"
+
+    def test_update_log_filepath_for_reporter_empty(self):
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "")
+        test_config.update_log_filepath_for_reporter()
+        assert test_config.get("log_filepath") == ""
+
+    def test_update_log_filepath_for_reporter_no_ext(self):
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo")
+        test_config.update_log_filepath_for_reporter()
+        assert test_config.get("log_filepath") == "/path/to/foo_ext"
+
+    def test_update_log_filepath_for_reporter_ext(self):
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo.log")
+        test_config.update_log_filepath_for_reporter()
+        assert test_config.get("log_filepath") == "/path/to/foo_ext.log"
+
+    def test_update_log_filepath_for_reporter_ext_multiple_dots(self):
+        test_config = apm_config.SolarWindsApmConfig()
+        test_config._set_config_value("log_filepath", "/path/to/foo.abc.def.xyz")
+        test_config.update_log_filepath_for_reporter()
+        assert test_config.get("log_filepath") == "/path/to/foo.abc.def_ext.xyz"
 
     def test_convert_to_bool_bool_true(self):
         test_config = apm_config.SolarWindsApmConfig()