python - 如何分析 SQLAlchemy 支持的应用程序？

Question

有人有分析 Python/SQLAlchemy 应用程序的经验吗？找出瓶颈和设计缺陷的最佳方法是什么？

我们有一个 Python 应用程序，其中数据库层由 SQLAlchemy 处理。该应用程序使用批处理设计，因此许多数据库请求是按顺序在有限的时间跨度内完成的。目前运行时间有点太长，因此需要进行一些优化。我们不使用 ORM 功能，数据库是 PostgreSQL。

Answer 1

有时只是简单的 SQL 日志记录(通过 python 的日志记录模块或通过 create_engine() 上的 echo=True 参数启用)可以让您了解事情需要多长时间.例如，如果您在 SQL 操作之后立即记录某些内容，您会在日志中看到类似这样的内容:

17:37:48,325 INFO  [sqlalchemy.engine.base.Engine.0x...048c] SELECT ...
17:37:48,326 INFO  [sqlalchemy.engine.base.Engine.0x...048c] {<params>}
17:37:48,660 DEBUG [myapp.somemessage] 

如果您在操作后立即记录 myapp.somemessage，您就会知道完成 SQL 部分需要 334 毫秒。

记录 SQL 还将说明是否正在发出数十/数百个查询，这些查询可以通过连接更好地组织成更少的查询。使用 SQLAlchemy ORM 时，“急切加载”功能提供给部分(contains_eager())或完全(eagerload()、eagerload_all()) 自动执行此事件，但如果没有 ORM，它只是意味着使用连接，以便可以将跨多个表的结果加载到一个结果集中，而不是随着深度的增加而增加查询数量(即 r + r* r2 + r*r2*r3 ...)

如果日志记录显示单个查询花费的时间过长，您需要详细说明在数据库中处理查询、通过网络发送结果、由 DBAPI 处理以及最终由SQLAlchemy 的结果集和/或 ORM 层。根据具体情况，每个阶段都可能出现各自的瓶颈。

为此，您需要使用分析，例如 cProfile 或 hotshot。这是我使用的装饰器:

import cProfile as profiler
import gc, pstats, time

def profile(fn):
    def wrapper(*args, **kw):
        elapsed, stat_loader, result = _profile("foo.txt", fn, *args, **kw)
        stats = stat_loader()
        stats.sort_stats('cumulative')
        stats.print_stats()
        # uncomment this to see who's calling what
        # stats.print_callers()
        return result
    return wrapper

def _profile(filename, fn, *args, **kw):
    load_stats = lambda: pstats.Stats(filename)
    gc.collect()

    began = time.time()
    profiler.runctx('result = fn(*args, **kw)', globals(), locals(),
                    filename=filename)
    ended = time.time()

    return ended - began, load_stats, locals()['result']

要分析一段代码，请将其放在带有装饰器的函数中:

@profile
def go():
    return Session.query(FooClass).filter(FooClass.somevalue==8).all()
myfoos = go()

分析的输出可用于了解时间花费在何处。例如，如果您看到所有时间都花在 cursor.execute() 中，那是对数据库的低级 DBAPI 调用，这意味着您的查询应该通过添加索引或重组查询和/或底层架构。对于该任务，我建议使用 pgadmin 及其图形 EXPLAIN 实用程序来查看查询正在做什么。

如果您看到数以千计的与获取行相关的调用，这可能意味着您的查询返回的行数比预期的多 - 由于连接不完整而导致的笛卡尔积可能会导致此问题。另一个问题是在类型处理中所花费的时间——诸如 Unicode 之类的 SQLAlchemy 类型将对绑定(bind)参数和结果列执行字符串编码/解码，这可能并非在所有情况下都需要。

配置文件的输出可能有点令人生畏，但经过一些练习后，它们很容易阅读。曾经有人在邮件列表中声称速度很慢，在让他发布配置文件的结果后，我能够证明速度问题是由于网络延迟 - 在 cursor.execute() 以及所有 Python 中花费的时间方法非常快，而大部分时间都花在了 socket.receive() 上。

如果您有雄心壮志，那么在 SQLAlchemy 单元测试中还有一个更复杂的 SQLAlchemy 分析示例，如果您浏览 http://www.sqlalchemy.org/trac/browser/sqlalchemy/trunk/test/aaa_profiling .在那里，我们使用装饰器进行测试，这些装饰器断言用于特定操作的方法调用的最大数量，因此如果 checkin 了一些低效的东西，测试将揭示它(重要的是要注意，在 Python 中，函数调用具有最高的任何操作的开销，并且调用次数通常与花费的时间几乎成正比)。值得注意的是“zoomark”测试使用了一种奇特的“SQL 捕获”方案，该方案从等式中减少了 DBAPI 的开销——尽管该技术对于普通的分析并不是真正必要的。