Fix excessive disk logging (#287)

* add truncation logic to limit message in file logger

* add unit test for filelogger

* add unit test for flush()

* add unit test for filelogger

* revert comment

* modify the write truncation logic and ut

* remove truncation method in filelogger

Author: feng-j678

src/core/src/local_loggers/FileLogger.py

@@ -25,6 +25,7 @@ def __init__(self, env_layer, log_file):
         self.log_file = log_file
         self.log_failure_log_file = log_file + ".failure"
         self.log_file_handle = None
+        self.max_msg_size = 32 * 1024 * 1024
         try:
             self.log_file_handle = self.env_layer.file_system.open(self.log_file, "a+")
         except Exception as error:
@@ -38,6 +39,8 @@ def __del__(self):
 
     def write(self, message, fail_silently=True):
         try:
+            if len(message) > self.max_msg_size:
+                message = message[:self.max_msg_size]
             if self.log_file_handle is not None:
                 self.log_file_handle.write(message)
         except Exception as error:
@@ -50,6 +53,8 @@ def write(self, message, fail_silently=True):
     def write_irrecoverable_exception(self, message):
         """ A best-effort attempt to write out errors where writing to the primary log file was interrupted"""
         try:
+            if len(message) > self.max_msg_size:
+                message = message[:self.max_msg_size]
             with self.env_layer.file_system.open(self.log_failure_log_file, 'a+') as fail_log:
                 timestamp = self.env_layer.datetime.timestamp()
                 fail_log.write("\n" + timestamp + "> " + message)
@@ -67,3 +72,4 @@ def close(self, message_at_close='<Log file was closed.>'):
                 self.write(str(message_at_close))
             self.log_file_handle.close()
             self.log_file_handle = None     # Not having this can cause 'I/O exception on closed file' exceptions
+

src/core/tests/Test_FileLogger.py

@@ -0,0 +1,150 @@
+# Copyright 2025 Microsoft Corporation
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+# Requires Python 2.7+
+import unittest
+from core.src.local_loggers.FileLogger import FileLogger
+
+
+class MockFileHandle:
+    def __init__(self, raise_on_write=False):
+        self.raise_on_write = raise_on_write
+        self.flushed = False
+        self.fileno_called = False
+        self.contents = ""
+        self.closed = False
+    
+    def write(self, message):
+        if self.raise_on_write:
+            raise Exception("Mock write exception")
+        self.contents += message
+    
+    def flush(self):
+        self.flushed = True
+
+    def fileno(self):
+        self.fileno_called = True
+        return 1  # mock file
+
+    def close(self):
+        self.closed = True
+
+    def __enter__(self):
+        return self
+
+    def __exit__(self, exc_type, exc_value, traceback):
+        self.close()
+
+
+class MockFileSystem:
+    def __init__(self):
+        self.files = {}
+
+    def open(self, file_path, mode):
+        if "error" in file_path:
+            raise Exception("Mock file open error")
+
+        if file_path not in self.files:
+            self.files[file_path] = MockFileHandle()
+
+        return self.files[file_path]
+
+
+class MockEnvLayer:
+    def __init__(self):
+        self.file_system = MockFileSystem()
+        self.datetime = self
+    
+    def timestamp(self):
+        return "2025-01-01T00:00:00Z"
+
+
+class TestFileLogger(unittest.TestCase):
+    def setUp(self):
+        self.mock_env_layer = MockEnvLayer()
+        self.log_file = "test.log"
+        self.file_logger = FileLogger(self.mock_env_layer, self.log_file)
+
+    def test_init_failure(self):
+        """ Test when initiation object file open throws exception """
+        self.mock_env_layer.file_system.open = lambda *args, **kwargs: (_ for _ in ()).throw(Exception("Mock file open error"))
+        with self.assertRaises(Exception) as context:
+            FileLogger(self.mock_env_layer, "error_log.log")
+
+        self.assertIn("Mock file open error", str(context.exception))
+    
+    def test_write(self):
+        """ Test FileLogger write() with no truncation """
+        message = "Test message"
+        self.file_logger.write(message)
+        self.assertEqual(self.file_logger.log_file_handle.contents, message)
+
+    def test_write_truncation(self):
+        """ Test FileLogger write() with truncation """
+        max_msg_size = 32 * 1024 * 1024
+        message = "A" * (32 * 1024 * 1024 + 10)
+        self.file_logger.write(message)
+        self.assertEqual(len(self.file_logger.log_file_handle.contents), max_msg_size)
+
+    def test_write_false_silent_failure(self):
+        """ Test FileLogger write(), throws exception raise_on_write is true """
+        self.file_logger.log_file_handle = MockFileHandle(raise_on_write=True)
+
+        with self.assertRaises(Exception) as context:
+            self.file_logger.write("test message", fail_silently=False)
+
+        self.assertIn("Fatal exception trying to write to log file", str(context.exception))
+
+    def test_write_irrecoverable_exception(self):
+        """ Test FileLogger write_irrecoverable_exception write failure log """
+        message = "test message"
+        self.file_logger.write_irrecoverable_exception(message)
+
+        self.assertIn(self.file_logger.log_failure_log_file, self.mock_env_layer.file_system.files)
+
+        failure_log = self.mock_env_layer.file_system.files[self.file_logger.log_failure_log_file]
+        expected_output = "\n2025-01-01T00:00:00Z> test message"
+
+        self.assertIn(expected_output, failure_log.contents)
+
+    def test_write_irrecoverable_exception_failure(self):
+        """ Test FileLogger write_irrecoverable_exception exception raised """
+        self.file_logger.log_failure_log_file = "error_failure_log.log"
+        message = "test message"
+
+        self.file_logger.write_irrecoverable_exception(message)
+
+        self.assertNotIn("error_failure_log.log", self.mock_env_layer.file_system.files)
+
+    def test_write_irrecoverable_exception_truncation(self):
+        """ Test FileLogger write_irrecoverable_exception write failure log with truncation """
+        timestamp_size = len("\n2025-01-01T00:00:00Z> ")
+        max_msg_size = 32 * 1024 * 1024
+        message = "A" * (32 * 1024 * 1024 + 10)
+        self.file_logger.write_irrecoverable_exception(message)
+
+        self.assertIn(self.file_logger.log_failure_log_file, self.mock_env_layer.file_system.files)
+        failure_log = self.mock_env_layer.file_system.files[self.file_logger.log_failure_log_file]
+        self.assertEqual(len(failure_log.contents), max_msg_size + timestamp_size)
+
+    def test_flush_success(self):
+        """ Test FileLogger flush() and fileno() are called"""
+        self.file_logger.flush()
+
+        self.assertTrue(self.file_logger.log_file_handle.flushed)
+        self.assertTrue(self.file_logger.log_file_handle.fileno_called)
+
+
+if __name__ == '__main__':
+    unittest.main()