Re-encode log messages to make sure we will not fail on writing logs

We need to be able to write poorly encoded messages in the logs,
so that we can easily identify the issue
Unfortiantly there is no encoding parameter for the FileHandler in python 3.6,
so we have to re-encode the message manually.

pleskdistup/common/src/log.py

@@ -1,4 +1,5 @@
 # Copyright 2023-2024. WebPros International GmbH. All rights reserved.
+import locale
 import logging
 
 import typing
@@ -9,10 +10,20 @@ class logger():
 
     is_streams_enabled = False
     streams_logger = logging.getLogger("distupgrade_streams")
+    encoding: str = locale.getpreferredencoding()
+
+    @staticmethod
+    def _re_decode_message(message: str) -> str:
+        return message.encode(logger.encoding, errors='backslashreplace').decode(logger.encoding, errors='backslashreplace')
 
     @staticmethod
     def init_logger(logfiles: typing.List[str], streams: typing.List[typing.Any],
-                    console: bool = False, loglevel: int = logging.INFO) -> None:
+                    console: bool = False, loglevel: int = logging.INFO, encoding: str = None) -> None:
+        if encoding is None:
+            logger.encoding = locale.getpreferredencoding()
+        else:
+            logger.encoding = encoding
+
         logger.files_logger.setLevel(loglevel)
         logger.streams_logger.setLevel(loglevel)
 
@@ -39,13 +50,14 @@ def init_logger(logfiles: typing.List[str], streams: typing.List[typing.Any],
 
     @staticmethod
     def reinit_logger(logfiles: typing.List[str], streams: typing.List[typing.Any],
-                      console: bool = False, loglevel: int = logging.INFO) -> None:
+                      console: bool = False, loglevel: int = logging.INFO, encoding: str = None) -> None:
         logger.files_logger = logging.getLogger("distupgrade_files")
         logger.streams_logger = logging.getLogger("distupgrade_streams")
-        logger.init_logger(logfiles, streams, console, loglevel)
+        logger.init_logger(logfiles, streams, console, loglevel, encoding=encoding)
 
     @staticmethod
     def debug(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
+        msg = logger._re_decode_message(msg)
         if to_file:
             logger.files_logger.debug(msg)
 
@@ -54,6 +66,7 @@ def debug(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
 
     @staticmethod
     def info(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
+        msg = logger._re_decode_message(msg)
         if to_file:
             logger.files_logger.info(msg)
 
@@ -62,6 +75,7 @@ def info(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
 
     @staticmethod
     def warn(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
+        msg = logger._re_decode_message(msg)
         if to_file:
             logger.files_logger.warn(msg)
 
@@ -70,6 +84,7 @@ def warn(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
 
     @staticmethod
     def err(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
+        msg = logger._re_decode_message(msg)
         if to_file:
             logger.files_logger.error(msg)
 
@@ -78,13 +93,13 @@ def err(msg: str, to_file: bool = True, to_stream: bool = True) -> None:
 
 
 def init_logger(logfiles: typing.List[str], streams: typing.List[typing.Any],
-                console: bool = False, loglevel: int = logging.INFO) -> None:
-    logger.init_logger(logfiles, streams, console, loglevel)
+                console: bool = False, loglevel: int = logging.INFO, encoding: str = None) -> None:
+    logger.init_logger(logfiles, streams, console, loglevel, encoding=encoding)
 
 
 def reinit_logger(logfiles: typing.List[str], streams: typing.List[typing.Any],
-                  console: bool = False, loglevel: int = logging.INFO) -> None:
-    logger.reinit_logger(logfiles, streams, console, loglevel)
+                  console: bool = False, loglevel: int = logging.INFO, encoding: str = None) -> None:
+    logger.reinit_logger(logfiles, streams, console, loglevel, encoding=encoding)
 
 
 def debug(msg: str, to_file: bool = True, to_stream: bool = True) -> None:

pleskdistup/common/tests/logtests.py

@@ -0,0 +1,47 @@
+# Copyright 2023-2024. WebPros International GmbH. All rights reserved.
+import locale
+import os
+import unittest
+
+import src.log as log
+
+
+class TestLog(unittest.TestCase):
+    DEFAULT_LOG_STORE = "test.log"
+
+    def setUp(self) -> None:
+        log.logger.init_logger([self.DEFAULT_LOG_STORE], [], console=False)
+
+    def tearDown(self) -> None:
+        if os.path.exists(self.DEFAULT_LOG_STORE):
+            os.unlink(self.DEFAULT_LOG_STORE)
+
+    def test_error_log(self):
+        log.err("Test message")
+        self.assertTrue(os.path.exists(self.DEFAULT_LOG_STORE))
+        with open(self.DEFAULT_LOG_STORE, "r") as log_file:
+            self.assertTrue("Test message" in log_file.read())
+
+    def test_no_debug_by_default(self):
+        log.debug("Test message")
+        self.assertTrue(os.path.exists(self.DEFAULT_LOG_STORE))
+        with open(self.DEFAULT_LOG_STORE, "r") as log_file:
+            self.assertEqual("", log_file.read())
+
+    def test_debug_log(self):
+        log.reinit_logger([self.DEFAULT_LOG_STORE], [], console=False, loglevel=log.logging.DEBUG)
+        log.debug("Test message")
+        self.assertTrue(os.path.exists(self.DEFAULT_LOG_STORE))
+        with open(self.DEFAULT_LOG_STORE, "r") as log_file:
+            self.assertTrue("Test message" in log_file.read())
+
+    def test_write_bad_encoded(self):
+        # To trigger an exception, we need to set the locale to a non-utf8 one
+        # but we can't be sure what locale will be installed on the test machine
+        # So it looks like it is enough to make sure message was re-decoded before
+        # writing to the log file by checking logfile content.
+        log.reinit_logger([self.DEFAULT_LOG_STORE], [], console=False, encoding='ascii')
+        log.err("Test message ü")
+        self.assertTrue(os.path.exists(self.DEFAULT_LOG_STORE))
+        with open(self.DEFAULT_LOG_STORE, "r") as log_file:
+            self.assertTrue("Test message \\xfc" in log_file.read())