Lazy logger

counterparty-core/counterpartycore/lib/api/wsgi.py

@@ -5,6 +5,7 @@
 import signal
 import sys
 import threading
+import time
 
 import gunicorn.app.base
 import waitress
@@ -25,6 +26,19 @@
 logger = logging.getLogger(config.LOGGER_NAME)
 
 
+class LazyLogger(metaclass=helpers.SingletonMeta):
+    def __init__(self):
+        self.last_message = None
+        self.last_print = 0
+        self.message_delay = 10
+
+    def debug(self, message, *args):
+        if message != self.last_message or self.last_print + self.message_delay < time.time():
+            logger.debug(message, *args)
+            self.last_message = message
+            self.last_print = time.time()
+
+
 def refresh_current_state(state_db, shared_backend_height):
     CurrentState().set_current_block_index(apiwatcher.get_last_block_parsed(state_db))
 
@@ -36,14 +50,14 @@ def refresh_current_state(state_db, shared_backend_height):
         return
 
     if current_backend_height > current_block_index:
-        logger.debug(
+        LazyLogger().debug(
             "Counterparty is currently behind Bitcoin Core. (Counterparty Block Height = %s, Bitcoin Core Block Height = %s, Network Block Height = %s)",
             current_block_index,
             current_block_count,
             current_backend_height,
         )
     elif current_backend_height < current_block_index:
-        logger.debug(
+        LazyLogger().debug(
             "Bitcoin Core is currently behind the network. (Counterparty Block Height = %s, Bitcoin Core Block Height = %s, Network Block Height = %s)",
             current_block_index,
             current_block_count,

counterparty-core/counterpartycore/test/mocks/conftest.py

@@ -105,17 +105,23 @@ def check_records(ledger_db, records):
 
     @staticmethod
     @contextmanager
-    def capture_log(caplog, message):
+    def capture_log(caplog, message, not_in=False):
         logger = logging.getLogger(config.LOGGER_NAME)
         caplog.at_level(6, logger=config.LOGGER_NAME)
         logger.propagate = True
         yield
         logger.propagate = False
         if isinstance(message, list):
             for m in message:
-                assert m in caplog.text
+                if not_in:
+                    assert m not in caplog.text
+                else:
+                    assert m in caplog.text
         else:
-            assert message in caplog.text
+            if not_in:
+                assert message not in caplog.text
+            else:
+                assert message in caplog.text
 
 
 @pytest.fixture

counterparty-core/counterpartycore/test/units/api/wsgi_test.py

@@ -0,0 +1,35 @@
+import time
+
+from counterpartycore.lib.api import wsgi
+
+
+def test_lazy_logger(caplog, test_helpers):
+    lazy_logger = wsgi.LazyLogger()
+    assert lazy_logger.last_message is None
+    assert lazy_logger.last_print == 0
+    assert lazy_logger.message_delay == 10
+
+    with test_helpers.capture_log(caplog, "Coucou"):
+        lazy_logger.debug("Coucou")
+    assert lazy_logger.last_message == "Coucou"
+    assert lazy_logger.last_print > 0
+    last_print = lazy_logger.last_print
+
+    caplog.clear()
+    with test_helpers.capture_log(caplog, "Coucou", not_in=True):
+        lazy_logger.debug("Coucou")
+    assert lazy_logger.last_message == "Coucou"
+    assert lazy_logger.last_print == last_print
+
+    lazy_logger.message_delay = 0.1
+    time.sleep(0.2)
+
+    caplog.clear()
+    with test_helpers.capture_log(caplog, "Coucou"):
+        lazy_logger.debug("Coucou")
+    assert lazy_logger.last_print > last_print
+    last_print = lazy_logger.last_print
+
+    with test_helpers.capture_log(caplog, "Hello"):
+        lazy_logger.debug("Hello")
+    assert lazy_logger.last_print > last_print