[INDY-1225] Implemented compression, increased log rotation interval (h…

…yperledger#607)

* Added option for log compression during rotation

Signed-off-by: Sergey Khoroshavin <[email protected]>

* Increased timed log rotation interval, turned compression on by default

Signed-off-by: Sergey Khoroshavin <[email protected]>

plenum/config.py

@@ -149,10 +149,11 @@
 
 
 # Log configuration
-logRotationWhen = 'D'
+logRotationWhen = 'W'
 logRotationInterval = 1
-logRotationBackupCount = 10
+logRotationBackupCount = 50
 logRotationMaxBytes = 100 * 1024 * 1024
+logRotationCompress = True
 logFormat = '{asctime:s} | {levelname:8s} | {filename:20s} ({lineno: >4}) | {funcName:s} | {message:s}'
 logFormatStyle = '{'
 logLevel = logging.NOTSET

plenum/test/test_log_rotation.py

@@ -2,33 +2,41 @@
 import logging
 import time
 import collections
+import gzip
+import pytest
 
 from stp_core.common.logging.TimeAndSizeRotatingFileHandler \
     import TimeAndSizeRotatingFileHandler
 
 
-def test_time_log_rotation(tdir_for_func):
+@pytest.fixture(params=[False, True], ids=["plain", "compressed"])
+def log_compression(request):
+    return request.param
+
+
+def test_time_log_rotation(tdir_for_func, log_compression):
     logDirPath = tdir_for_func
     logFile = os.path.join(logDirPath, "log")
     logger = logging.getLogger('test_time_log_rotation-logger')
 
     logger.setLevel(logging.DEBUG)
-    handler = TimeAndSizeRotatingFileHandler(logFile, interval=1, when='s')
+    handler = TimeAndSizeRotatingFileHandler(
+        logFile, interval=1, when='s', compress=log_compression)
     logger.addHandler(handler)
     for i in range(3):
         time.sleep(1)
         logger.debug("line")
     assert len(os.listdir(logDirPath)) == 4  # initial + 3 new
 
 
-def test_size_log_rotation(tdir_for_func):
+def test_size_log_rotation(tdir_for_func, log_compression):
     logDirPath = tdir_for_func
     logFile = os.path.join(logDirPath, "log")
     logger = logging.getLogger('test_time_log_rotation-logger')
 
     logger.setLevel(logging.DEBUG)
     handler = TimeAndSizeRotatingFileHandler(
-        logFile, maxBytes=(4 + len(os.linesep)) * 4 + 1)
+        logFile, maxBytes=(4 + len(os.linesep)) * 4 + 1, compress=log_compression)
     logger.addHandler(handler)
     for i in range(20):
         logger.debug("line")
@@ -37,14 +45,14 @@ def test_size_log_rotation(tdir_for_func):
     assert len(os.listdir(logDirPath)) == 5
 
 
-def test_time_and_size_log_rotation(tdir_for_func):
+def test_time_and_size_log_rotation(tdir_for_func, log_compression):
     logDirPath = tdir_for_func
     logFile = os.path.join(logDirPath, "log")
     logger = logging.getLogger('test_time_and_size_log_rotation-logger')
 
     logger.setLevel(logging.DEBUG)
     handler = TimeAndSizeRotatingFileHandler(
-        logFile, maxBytes=(4 + len(os.linesep)) * 4 + 1, interval=1, when="s")
+        logFile, maxBytes=(4 + len(os.linesep)) * 4 + 1, interval=1, when="s", compress=log_compression)
     logger.addHandler(handler)
 
     for i in range(20):
@@ -57,7 +65,7 @@ def test_time_and_size_log_rotation(tdir_for_func):
     assert len(os.listdir(logDirPath)) == 8
 
 
-def test_time_and_size_log_rotation1(tdir_for_func):
+def test_time_and_size_log_rotation1(tdir_for_func, log_compression):
     log_dir_path = tdir_for_func
     logFile = os.path.join(log_dir_path, "log")
     logger = logging.getLogger('test_time_and_size_log_rotation-logger1')
@@ -73,7 +81,7 @@ def test_time_and_size_log_rotation1(tdir_for_func):
     handler = TimeAndSizeRotatingFileHandler(
         logFile,
         maxBytes=(record_length + len(os.linesep)) * record_per_file + 1,
-        interval=1, when="h", backupCount=backup_count, utc=True)
+        interval=1, when="h", backupCount=backup_count, utc=True, compress=log_compression)
     logger.addHandler(handler)
 
     for i in range(1, record_count + 1):
@@ -90,6 +98,7 @@ def test_time_and_size_log_rotation1(tdir_for_func):
     assert len(cir_buffer) == len(circ_buffer_set)
     assert len(os.listdir(log_dir_path)) == (backup_count + 1)
     for file_name in os.listdir(log_dir_path):
-        with open(os.path.join(log_dir_path, file_name)) as file:
+        open_fn = gzip.open if file_name.endswith(".gz") else open
+        with open_fn(os.path.join(log_dir_path, file_name), "rt") as file:
             for line in file.readlines():
                 assert line.strip() in circ_buffer_set

stp_core/common/log.py

@@ -97,7 +97,8 @@ def enableFileLogging(self, filename):
             interval=self._config.logRotationInterval,
             backupCount=self._config.logRotationBackupCount,
             utc=True,
-            maxBytes=self._config.logRotationMaxBytes)
+            maxBytes=self._config.logRotationMaxBytes,
+            compress=self._config.logRotationCompress)
         self._setHandler('file', new)
 
     def _setHandler(self, typ: str, new_handler):

stp_core/common/logging/TimeAndSizeRotatingFileHandler.py

@@ -1,4 +1,5 @@
 import os
+import gzip
 from logging.handlers import TimedRotatingFileHandler
 from logging.handlers import RotatingFileHandler
 
@@ -7,21 +8,33 @@ class TimeAndSizeRotatingFileHandler(TimedRotatingFileHandler, RotatingFileHandl
 
     def __init__(self, filename, when='h', interval=1, backupCount=0,
                  encoding=None, delay=False, utc=False, atTime=None,
-                 maxBytes=0):
+                 maxBytes=0, compress=False):
 
         TimedRotatingFileHandler.__init__(self, filename, when, interval,
                                           backupCount, encoding, delay,
                                           utc, atTime)
         self.maxBytes = maxBytes
+        self.compress = compress
 
     def shouldRollover(self, record):
         return bool(TimedRotatingFileHandler.shouldRollover(self, record)) or \
             bool(RotatingFileHandler.shouldRollover(self, record))
 
-    def rotation_filename(self, default_name: str):
+    def rotate(self, source, dest):
+        source_gz = source.endswith(".gz")
+        dest_gz = dest.endswith(".gz")
+        if source_gz == dest_gz:
+            os.rename(source, dest)
+            return
+        # Assuming that not source_gz and dest_gz
+        with open(source, 'rb') as f_in, gzip.open(dest, 'wb') as f_out:
+            f_out.writelines(f_in)
+        os.remove(source)
 
-        if not os.path.exists(default_name):
-            return default_name
+    def rotation_filename(self, default_name: str):
+        compressed_name = self._compressed_filename(default_name)
+        if not os.path.exists(compressed_name):
+            return compressed_name
 
         dir = os.path.dirname(default_name)
         defaultFileName = os.path.basename(default_name)
@@ -33,13 +46,19 @@ def rotation_filename(self, default_name: str):
                 index = self._file_index(fileName)
                 if index > maxIndex:
                     maxIndex = index
-        return "{}.{}".format(default_name, maxIndex + 1)
+        return self._compressed_filename("{}.{}".format(default_name, maxIndex + 1))
+
+    def _compressed_filename(self, file_name):
+        return "{}.gz".format(file_name) if self.compress else file_name
 
     @staticmethod
     def _file_index(file_name):
         split = file_name.split(".")
+        index = split[-1]
+        if index == "gz":
+            index = split[-2]
         try:
-            return int(split[-1])
+            return int(index)
         except ValueError:
             return 0
 
@@ -59,6 +78,8 @@ def getFilesToDelete(self):
         for fileName in fileNames:
             if fileName[:plen] == prefix:
                 suffix = fileName[plen:]
+                if suffix.endswith(".gz"):
+                    suffix = suffix[:-3]
                 if self.extMatch.match(suffix):
                     result.append(os.path.join(dirName, fileName))
         if len(result) <= self.backupCount:

stp_core/config.py

@@ -7,10 +7,11 @@
 baseDir = os.getcwd()
 
 # Log configuration
-logRotationWhen = 'D'
+logRotationWhen = 'W'
 logRotationInterval = 1
-logRotationBackupCount = 10
+logRotationBackupCount = 50
 logRotationMaxBytes = 100 * 1024 * 1024
+logRotationCompress = True
 logFormat = '{asctime:s} | {levelname:8s} | {filename:20s} ({lineno:d}) | {funcName:s} | {message:s}'
 logFormatStyle = '{'