bigywater.tech
Flask · 162

Flask Profiler

怎么知道一个 Flask 视图的时间花在哪?Werkzeug 自带的剖析中间件怎么用?它会拖慢多少?采样式剖析器有什么不同?这篇对同一个混合视图用两种剖析器各跑一遍。

5.4 倍
ProfilerMiddleware 对一个几乎空的视图增加的耗时倍数
profile_dir
把每个请求的剖析结果写成 .prof 文件的参数
调用树
pyinstrument 输出的形式,按调用路径展示耗时

ProfilerMiddleware

实测 · 本机执行输出
  响应: 200
  --------------------------------------------------------------------------------
  PATH: '/mixed'
           74998 function calls (74470 primitive calls) in 0.044 seconds
     Ordered by: internal time, call count
     List reduced from 444 to 8 due to restriction <8>
     ncalls  tottime  percall  cumtime  percall filename:lineno(function)
          1    0.030    0.030    0.030    0.030 {built-in method time.sleep}
          1    0.004    0.004    0.007    0.007 {built-in method builtins.sum}
      60001    0.003    0.000    0.003    0.000 <实验目录>/exp/f162.py:9(<genexpr>)
          1    0.002    0.002    0.003    0.003 <实验目录>/exp/f162.py:10(json_work)
          2    0.001    0.001    0.001    0.001 <stdlib>/json/encoder.py:207(iterencode)
        802    0.000    0.000    0.001    0.000 <site-packages>/markupsafe/__init__.py:24(escape)
        804    0.000    0.000    0.000    0.000 <site-packages>/markupsafe/__init__.py:122(__new__)
         12    0.000    0.000    0.001    0.000 {method 'join' of 'str' objects}
  --------------------------------------------------------------------------------

上一篇:慢 SQL 统计;下一篇:模板渲染耗时。

剖析的开销

实测 · 本机执行输出
  没有剖析                           /mixed 中位数   38.46 ms | /fast 中位数     109 µs
  ProfilerMiddleware(cProfile)   /mixed 中位数   47.39 ms | /fast 中位数     589 µs

保存 .prof 文件

实测 · 本机执行输出
  生成的文件: ['GET.mixed.41ms.1790924534.prof']
  按 tottime(函数自身耗时,不含子调用)排序的前几行:
    Fri Oct  2 15:02:14 2026    <实验目录>/fltmp/f162prof/GET.mixed.41ms.1790924534.prof
             70067 function calls (69913 primitive calls) in 0.041 seconds
       Ordered by: internal time
       List reduced from 367 to 6 due to restriction <6>
       ncalls  tottime  percall  cumtime  percall filename:lineno(function)
            1    0.030    0.030    0.030    0.030 {built-in method time.sleep}
            1    0.004    0.004    0.007    0.007 {built-in method builtins.sum}
        60001    0.003    0.000    0.003    0.000 <实验目录>/exp/f162.py:9(<genexpr>)
            2    0.001    0.001    0.001    0.001 <stdlib>/json/encoder.py:207(iterencode)
            1    0.001    0.001    0.002    0.002 <实验目录>/exp/f162.py:10(json_work)
          802    0.000    0.000    0.001    0.000 <site-packages>/markupsafe/__init__.py:24(escape)

采样式剖析

实测 · 本机执行输出
    _     ._   __/__   _ _  _  _ _/_   Recorded: 15:02:14  Samples:  12
   /_//_/// /_\ / //_// / //_'/ //     Duration: 0.043     CPU time: 0.013
  /   _/                      v5.1.3
  Profile at <实验目录>/exp/f162.py:40
  0.043 <module>  f162.py:1
  `- 0.043 FlaskClient.get  werkzeug/test.py:1163
        [7 frames hidden]  flask, werkzeug
           0.043 Flask.dispatch_request  flask/app.py:879
           `- 0.043 mixed  f162.py:12
              |- 0.030 sleep  <built-in>
              |- 0.008 slow_helper  f162.py:9
              |  |- 0.005 <genexpr>  f162.py:9
              |  `- 0.003 [self]  f162.py
              |- 0.002 json_work  f162.py:10
              |  `- 0.002 dumps  json/__init__.py:185
              |     `- 0.002 JSONEncoder.encode  json/encoder.py:185
  pyinstrument(1 ms 采样间隔)下 /mixed 中位数 40.95 ms

pyinstrument 是我额外装进环境的,不是 Flask 或 Werkzeug 自带的。

分步演示

Flask Profiler
本步的对象

    本文用到的工具与边界

    • 本机 macOS 27 arm64 / Python 3.14.7 / Flask 3.1.3 / Werkzeug 3.1.9 / Jinja2 3.1.6 / SQLAlchemy 2.1.1 / gunicorn 26.2.0(都装在自己的虚拟环境里);大多数实验用 Flask 的 test_client(直接调用 WSGI 应用,不经过网络),需要真实 HTTP 时另起 gunicorn 或开发服务器(端口 9600 以上,本机 127.0.0.1);计时用 time.perf_counter,数字每次运行会有小幅抖动。Werkzeug ProfilerMiddleware、pyinstrument 5.1.3
    • 没有验证:在真实的 gunicorn 多进程下使用 ProfilerMiddleware(.prof 文件按进程分开)、py-spy 等外部采样器附着到运行中的进程、内存剖析(tracemalloc 在第 117 篇用过)、火焰图可视化
    京ICP备2026067502号-1京公网安备11010502063487号