profiler.output_text: float division by zero

[antoineqian]

Hi I use this middleware for my fastapi app

@app.middleware("http")
async def profile_request(request: Request, call_next: Callable):
    with Profiler(interval=0.001, async_mode="enabled") as profiler:
        response = await call_next(request)
    logger.warning(profiler.output_text())
    return response

However, I get this error when testing an endpoint. The error only happens for this endpoint, and I don't understand why

+ Exception Group Traceback (most recent call last):
  |   File "/home/runner/work/match-making/match-making/tests/local/integration/matching_scenarios/****.py", line 71, in test_***
  |     navigate = await client_test.post(
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1848, in post
  |     return await self.request(
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1530, in request
  |     return await self.send(request, auth=auth, follow_redirects=follow_redirects)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1617, in send
  |     response = await self._send_handling_auth(
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1645, in _send_handling_auth
  |     response = await self._send_handling_redirects(
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1682, in _send_handling_redirects
  |     response = await self._send_single_request(request)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_client.py", line 1719, in _send_single_request
  |     response = await transport.handle_async_request(request)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/httpx/_transports/asgi.py", line 162, in handle_async_request
  |     await self.app(scope, receive, send)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
  |     await super().__call__(scope, receive, send)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
  |     await self.middleware_stack(scope, receive, send)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
  |     raise exc
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
  |     await self.app(scope, receive, _send)
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 106, in __call__
  |     async with anyio.create_task_group() as task_group:
  |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 678, in __aexit__
  |     raise BaseExceptionGroup(
  | exceptiongroup.ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
  +-+---------------- 1 ----------------
    | Traceback (most recent call last):
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/anyio/streams/memory.py", line 97, in receive
    |     return self.receive_nowait()
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/anyio/streams/memory.py", line 92, in receive_nowait
    |     raise WouldBlock
    | anyio.WouldBlock
    | 
    | During handling of the above exception, another exception occurred:
    | 
    | Traceback (most recent call last):
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 78, in call_next
    |     message = await recv_stream.receive()
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/anyio/streams/memory.py", line 112, in receive
    |     raise EndOfStream
    | anyio.EndOfStream
    | 
    | During handling of the above exception, another exception occurred:
    | 
    | Exception Group Traceback (most recent call last):
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 108, in __call__
    |     response = await self.dispatch_func(request, call_next)
    |   File "/home/runner/work/match-making/match-making/src/main.py", line 137, in time_request
    |     response = await call_next(request)
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 84, in call_next
    |     raise app_exc
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 70, in coro
    |     await self.app(scope, receive_or_disconnect, send_no_error)
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 106, in __call__
    |     async with anyio.create_task_group() as task_group:
    |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 678, in __aexit__
    |     raise BaseExceptionGroup(
    | exceptiongroup.ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
    +-+---------------- 1 ----------------
      | Traceback (most recent call last):
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/starlette/middleware/base.py", line 108, in __call__
      |     response = await self.dispatch_func(request, call_next)
      |   File "/home/runner/work/match-making/match-making/src/main.py", line 130, in profile_request
      |     logger.warning(profiler.output_text())
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/profiler.py", line 297, in output_text
      |     return self.output(
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/profiler.py", line 337, in output
      |     return renderer.render(session)
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/renderers/console.py", line 63, in render
      |     result += self.render_frame(self.root_frame)
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/renderers/console.py", line 97, in render_frame
      |     result = f"***indent***self.frame_description(frame)***\n"
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/renderers/console.py", line 167, in frame_description
      |     time_color = self._ansi_color_for_time(time)
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/renderers/console.py", line 192, in _ansi_color_for_time
      |     proportion_of_total = self.frame_proportion_of_total_time(time)
      |   File "/opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/site-packages/pyinstrument/renderers/console.py", line 189, in frame_proportion_of_total_time
      |     return time / self.root_frame.time
      | ZeroDivisionError: float division by zero

pyinstrument: 4.6.2
python: 3.10
fastapi: 0.95.1

Thanks in advance for your help

[joerick]

It looks like there's a bug here, it's caused by a profile that has zero duration. The simplest fix would be to add a special case to frame_proportion_of_total_time to just return 1 if self.root_frame.time is zero. If you have time to submit a PR, that would be appriciated!