log_exception context manager avoids spamming by not logging every exception (#126)

Author: almarklein

rendercanvas/_coreutils.py

@@ -5,6 +5,7 @@
 import os
 import re
 import sys
+import time
 import weakref
 import logging
 import ctypes.util
@@ -18,7 +19,7 @@
 logger.setLevel(logging.WARNING)
 
 
-err_hashes = {}
+err_hashes = {}  # hash -> [short-message, count, next-time]
 
 _re_wgpu_ob = re.compile(r"`<[a-z|A-Z]+-\([0-9]+, [0-9]+, [a-z|A-Z]+\)>`")
 
@@ -47,16 +48,31 @@ def log_exception(kind):
         msg = str(err)
         msgh = error_message_hash(msg)
         if msgh not in err_hashes:
+            # Prepare a short variant of the message for later use
+            short_msg = kind + ": " + msg.split("\n")[0].strip()
+            short_msg = short_msg if len(short_msg) <= 70 else short_msg[:69] + "…"
+            err_hashes[msgh] = [short_msg, 1, 0]
             # Provide the exception, so the default logger prints a stacktrace.
             # IDE's can get the exception from the root logger for PM debugging.
-            err_hashes[msgh] = 1
             logger.error(kind, exc_info=err)
         else:
             # We've seen this message before, return a one-liner instead.
-            err_hashes[msgh] = count = err_hashes[msgh] + 1
-            msg = kind + ": " + msg.split("\n")[0].strip()
-            msg = msg if len(msg) <= 70 else msg[:69] + "…"
-            logger.error(msg + f" ({count})")
+            short_count_tm = err_hashes[msgh]
+            short, count, tm = short_count_tm
+            short_count_tm[1] = count = count + 1
+            # Show the message now?
+            show_message = False
+            cur_time = time.perf_counter()
+            if count <= 5:
+                show_message = True
+            else:
+                if cur_time > tm:
+                    show_message = True
+            # Log the messages and schedule when to show it next.
+            # Next message is after 1-3 seconds (3 when count reaches 300).
+            if show_message:
+                short_count_tm[2] = cur_time + min(max(count / 100, 1), 3)
+                logger.error(f"{short} ({count})")
 
 
 # %% Weak bindings