python - slow_callback_duration に関連する asyncio set_result の動作を理解する

Question

asyncio イベント ループとして uvloop を使用して tornado の上に構築された、実行中の Python Web サービスのパフォーマンスをデバッグしようとしています。同時実行性を改善するために、イベント ループをブロックする同期コードが実行されている場所を探しています。この目的のために、サービスごとに debug と slow_callback_duration を次のように構成しました。

    uvloop.install()
    loop = asyncio.get_event_loop()
    loop.set_debug(True)
    loop.slow_callback_duration = 0.05
    server()

このコードを有効にすると、次のような多数のスロー コールバック ログ行が表示されます。

[W 210217 18:12:24.052 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad2e3cd6a8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.105 seconds
[W 210217 18:12:24.164 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad4d14f768> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.060 seconds
[W 210217 18:12:24.255 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad705e2618> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.083 seconds
[W 210217 18:12:24.387 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad9b08dd68> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.077 seconds
[W 210217 18:12:24.682 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad3716f4c8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.058 seconds
[W 210217 18:12:24.899 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad9b08d528> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.191 seconds
[W 210217 18:12:24.970 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad3706ad68> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.063 seconds
[W 210217 18:12:25.117 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad2e57c3a8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.088 seconds

私の特定の python ビルドでは、その行はof/tasks.py:711内のこの呼び出しを参照しています。__done__callbackgather

            if outer._cancel_requested:
                # If gather is being cancelled we must propagate the
                # cancellation regardless of *return_exceptions* argument.
                # See issue 32684.
                outer.set_exception(futures.CancelledError())
            else:
                outer.set_result(results) <--- This line

このデバッグ ログの行が実際に何を表しているのかをよりよく理解したいと思います。スロー コールバックの動作に関する私の (限られた) 理解から、gather のラッピング フューチャでの実際の実行にset_resultは長い時間がかかるように見えますが、これは少しおかしいようです。このデバッグ ログから詳細を取得したり、遅いコールバックが報告されたときにイベント ループが実際に実行しているコードを特定したりする方法はありますか?