From 4ea507270b7b886ce5fc40c35aefff4ad71ec520 Mon Sep 17 00:00:00 2001
From: kormax <3392860+kormax@users.noreply.github.com>
Date: Sun, 17 Mar 2024 14:30:15 +0200
Subject: [PATCH] Add slow_callback_duration logging

---
 qasync/__init__.py | 25 +++++++++++++++++++++++--
 1 file changed, 23 insertions(+), 2 deletions(-)

diff --git a/qasync/__init__.py b/qasync/__init__.py
index 3363e97..a47e988 100644
--- a/qasync/__init__.py
+++ b/qasync/__init__.py
@@ -233,6 +233,13 @@ def __exit__(self, *args):
         self.shutdown()
 
 
+def _format_handle(handle: asyncio.Handle):
+    cb = getattr(handle, "_callback", None)
+    if isinstance(getattr(cb, '__self__', None), asyncio.tasks.Task):
+        return repr(cb.__self__)
+    return str(handle)
+
+
 def _make_signaller(qtimpl_qtcore, *args):
     class Signaller(qtimpl_qtcore.QObject):
         try:
@@ -275,8 +282,22 @@ def timerEvent(self, event):  # noqa: N802
                 if handle._cancelled:
                     self.__log_debug("Handle %s cancelled", handle)
                 else:
-                    self.__log_debug("Calling handle %s", handle)
-                    handle._run()
+                    if self.__debug_enabled:
+                        # This may not be the most efficient thing to do, but it removes the need to sync
+                        # "slow_callback_duration" and "_current_handle" variables
+                        loop = asyncio.get_event_loop()
+                        try:
+                            loop._current_handle = handle
+                            self._logger.debug("Calling handle %s", handle)
+                            t0 = time.time()
+                            handle._run()
+                            dt = time.time() - t0
+                            if dt >= loop.slow_callback_duration:
+                                self._logger.warning('Executing %s took %.3f seconds', _format_handle(handle), dt)
+                        finally:
+                            loop._current_handle = None
+                    else:
+                        handle._run()
             finally:
                 del self.__callbacks[timerid]
                 handle = None