CabbageDevelopment / qasync

Python library for using asyncio in Qt-based applications.
BSD 2-Clause "Simplified" License
321 stars 45 forks source link

Add slow_callback_duration logging #114

Open kormax opened 6 months ago

kormax commented 6 months ago

This PR resolves an issue encountered in #100 by adding functionality for logging slow handle._run invocations the same way it's done by asyncio.BaseEventLoop(events.AbstractEventLoop).

It the modifies _SimpleTimer.timerEvent function by adding handle invocation time tracking in case debug mode is enabled, tightly mimicking the code from asyncio.base_events.

Results of this change can be compared by running the following code:

1.1. asyncio plain code

# Test asyncio example

import asyncio
import time

async def main():
    time.sleep(1)  # Block event loop

if __name__ == "__main__":
    loop = asyncio.get_event_loop()
    loop.set_debug(True)  # Enable debug
    loop.slow_callback_duration = 0.1
    loop.run_until_complete(main())

1.2. asyncio plain result

Executing <Task finished name='Task-1' coro=<main() done, defined at /Users/username/Documents/qasync_demo.py/blocking_timer_asyncio.py:5> result=None created at /lib/python3.8/asyncio/base_events.py:595> took 1.005 seconds

2.1. qasync code

# Qasync loop example

import time

from qtpy.QtGui import QGuiApplication
from qasync import QEventLoop

async def main():
    time.sleep(1)  # Block event loop

if __name__ == "__main__":
    app = QGuiApplication([])
    loop = QEventLoop(app)
    loop.set_debug(True)  # Enable debug
    loop.slow_callback_duration = 0.1
    loop.run_until_complete(main())

2.2. qasync result

Executing <Task finished name='Task-1' coro=<main() done, defined at /Users/username/Documents/qasync_demo.py/blocking_timer_qasync.py:7> result=None created at /Users/username/Documents/qasync/qasync/__init__.py:415> took 1.001 seconds

P.S. The _current_handle is set during debug handle invocations in order to improve logging in case asyncio.BaseEventLoop.default_exception_handler is set as an exception handler and an exception occurs. It's not mandatory for this change, but is nice to have, considering it's set in the same part of the code.