Как мне следить за тем, насколько занят цикл событий Python? - PullRequest
0 голосов
/ 16 января 2019

У меня есть асинхронное приложение, которое обслуживает запросы через aiohttp и выполняет другие асинхронные задачи (взаимодействие с базой данных, обработка сообщений, отправка запросов в качестве HTTP-клиента). Я хотел бы проследить, насколько занят цикл обработки событий, возможно, сколько времени он тратит на выполнение кода, а не на ожидание завершения select.

Есть ли способ измерить это с помощью стандартных событий библиотеки или других сторонних циклов (uvloop)?

В частности, я хотел бы, чтобы показатель насыщенности был в процентах, а не просто двоичный файл "занят", который этот вопрос , кажется, решает.

1 Ответ

0 голосов
/ 17 января 2019

Копание исходного кода показывает следующее:

  1. Цикл событий в основном выполняет _run_once в while True loop
  2. _run_once выполняет все действия , включая , ожидая завершения select
  3. timeout для ожидания select не хранится где-либо вне _run_once

Ничто не мешает нам переопределить _run_once время, которое нам нужно.

Вместо того, чтобы справиться с полной реализацией _run_once, мы можем предположить, что время прямо перед select - это когда _run_once началось (потому что выше select ничего не происходит), а время сразу после select - когда _process_events запущено.

От слов к делу:

import asyncio


class MeasuredEventLoop(asyncio.SelectorEventLoop):
    def __init__(self, *args, **kwargs):
        super().__init__(*args, **kwargs)
        self._total_time = 0
        self._select_time = 0

        self._before_select = None

    # TOTAL TIME:
    def run_forever(self):
        started = self.time()
        try:
            super().run_forever()
        finally:
            finished = self.time()
            self._total_time = finished - started

    # SELECT TIME:
    def _run_once(self):
        self._before_select = self.time()
        super()._run_once()

    def _process_events(self, *args, **kwargs):
        after_select = self.time()
        self._select_time += after_select - self._before_select
        super()._process_events(*args, **kwargs)

    # REPORT:
    def close(self, *args, **kwargs):
        super().close(*args, **kwargs)

        select = self._select_time
        cpu = self._total_time - self._select_time
        total = self._total_time

        print(f'Waited for select: {select:.{3}f}')
        print(f'Did other stuff: {cpu:.{3}f}')
        print(f'Total time: {total:.{3}f}')

Давайте проверим это:

import time


async def main():
    await asyncio.sleep(1)  # simulate I/O, will be handled by selectors
    time.sleep(0.01)        # CPU job, executed here, outside event loop
    await asyncio.sleep(1)
    time.sleep(0.01)


loop = MeasuredEventLoop()
asyncio.set_event_loop(loop)
try:
    loop.run_until_complete(main())
finally:
    loop.close()

Результат:

Waited for select: 2.000
Did other stuff: 0.032
Total time: 2.032

Давайте проверим это по коду с реальным вводом / выводом:

import aiohttp


async def io_operation(delay):
    async with aiohttp.ClientSession() as session:
        async with session.get(f'http://httpbin.org/delay/{delay}') as resp:
            await resp.text()


async def main():
    await asyncio.gather(*[
        io_operation(delay=1),
        io_operation(delay=2),
        io_operation(delay=3),
    ])

Результат:

Waited for select: 3.250
Did other stuff: 0.016
Total time: 3.266
...