Performance

Why is my application slow after upgrading to 1.4 and/or 2.x?

バージョン1.4のSQLAlchemyには:ref:SQL compilation caching facility <sql_caching>`が含まれています。これにより、CoreとORM SQL構文が、結果を文から取得するために使用される他の構造情報と共に、文字列化された形式をキャッシュできるようになり、構造的に等価な別の構文が次に使用されるときに、比較的高価な文字列コンパイルプロセスをスキップできるようになります。このシステムは、 :class:`_schema.Column 、 select() 、 TypeEngine オブジェクトなどのオブジェクトを含むすべてのSQL構文に実装されている機能に依存して、SQLコンパイルプロセスに影響を与える程度までそれらの状態を完全に表現する キャッシュキー を生成します。

キャッシュシステムを使用すると、SQL構文を文字列に繰り返し変換する時間に関して、SQLAlchemy 1.4以上のパフォーマンスをSQLAlchemy 1.3よりも向上させることができます。ただし、これが機能するのは、使用中の方言とSQL構文に対してキャッシュが有効になっている場合のみです。有効になっていない場合、文字列のコンパイルは通常SQLAlchemy 1.3と同様になりますが、場合によっては速度がわずかに低下します。

ただし、SQLAlchemyの新しいキャッシュシステムが(以下の理由で)無効になっている場合、ORMのパフォーマンスが1.3やそれ以前のリリースよりも実際に大幅に低下する可能性があります。これは、1.3以前のリリースでは、今ではレガシーとなった BakedQuery システムを使用していたORMレイジーローダーやオブジェクトリフレッシュクエリ内のキャッシュが不足しているためです。1.4に切り替えたときに、アプリケーションのパフォーマンス(操作の完了までの時間で測定)が大幅に(30%以上)低下している場合は、これが問題の原因である可能性が高く、以下の手順で軽減します。

See also

SQL Compilation Caching - キャッシュシステムの概要

Object will not produce a cache key, Performance Implications - キャッシングを有効にしない要素に対して生成される警告に関する追加情報です。

Step one - turn on SQL logging and confirm whether or not caching is working

ここでは、 engine logging で説明されているテクニックを使用して、 [no key] や [dialect does not support caching] を含む文を探します。キャッシュシステムに正常に参加しているSQL文のインジケータは、文が最初に呼び出されたときには [generated in Xs] と表示され、その後の文の大部分では [cached since Xs ago] と表示されます。特にSELECT文で [no key] が一般的な場合や、 [dialect does not support caching] のためにキャッシュが完全に無効になっている場合、これが大幅なパフォーマンス低下の原因となる可能性があります。

See also

Estimating Cache Performance Using Logging

Step two - identify what constructs are blocking caching from being enabled

文がキャッシュされていないと仮定すると、アプリケーションのログ(SQLAlchemy 1.4.28以降のみ)の早い段階で、ダイアレクト、 TypeEngine オブジェクト、キャッシュされていないSQL構文を示す警告が出力されるはずです。

TypeDecorator や UserDefinedType を継承するようなユーザ定義のデータ型の場合、警告は以下のようになります:

sqlalchemy.ext.SAWarning: MyType will not produce a cache key because the ``cache_ok`` attribute is not set to True. This can have significant performance implications including some performance degradations in comparison to prior SQLAlchemy versions. Set this attribute to True if this type object's state is safe to use in a cache key, or False to disable this warning.

Custom SQL Constructs and Compilation Extension で説明されているテクニックを使用して構築されたものなど、カスタムおよびサードパーティのSQL要素の場合、これらの警告は次のようになります:

sqlalchemy.exc.SAWarning: Class MyClass will not make use of SQL
compilation caching as it does not set the 'inherit_cache' attribute to
``True``. This can have significant performance implications including some
performance degradations in comparison to prior SQLAlchemy versions. Set
this attribute to True if this object can make use of the cache key
generated by the superclass. Alternatively, this attribute may be set to
False which will disable this warning.

Dialect クラス階層を使用するカスタムおよびサードパーティのダイアレクトの場合、警告は次のようになります:

sqlalchemy.exc.SAWarning: Dialect database:driver will not make use of SQL
compilation caching as it does not set the 'supports_statement_cache'
attribute to ``True``. This can have significant performance implications
including some performance degradations in comparison to prior SQLAlchemy
versions. Dialect maintainers should seek to set this attribute to True
after appropriate development and testing for SQLAlchemy 1.4 caching
support. Alternatively, this attribute may be set to False which will
disable this warning.

Step three - enable caching for the given objects and/or seek alternatives

キャッシュの不足を緩和する手順は次のとおりです。:

  • TypeDecorator , UserDefinedType , および PickleType などのサブクラスから拡張されるすべてのカスタム型に対して、 ExternalType.cache_ok を確認して True に設定します。カスタム型に、SQLのレンダリング方法に影響する追加の状態属性が含まれていない場合にのみ、これを設定します。:

    class MyCustomType(TypeDecorator):
    cache_ok = True
    impl = String

    使用されている型がサードパーティのライブラリからのものである場合は、そのライブラリのメンテナに相談して、調整してリリースできるようにしてください。

    See also

    ExternalType.cache_ok - カスタムデータ型のキャッシュを有効にするための要件の背景です。

  • サードパーティのダイアレクトが Dialect.supports_statement_cache を True に設定していることを確認してください。これは、サードパーティのダイアレクトのメンテナが、そのダイアレクトがSQLAlchemy 1.4以降で動作することを確認しており、そのダイアレクトにはキャッシュの妨げとなるコンパイル機能が含まれていないことを示しています。実際にキャッシュを妨げる可能性のある一般的なコンパイルパターンがいくつかあるので、ダイアレクトのメンテナがこれを注意深くチェックしてテストし、キャッシュで動作しないレガシーパターンを調整することが重要です。

    See also

    Caching for Third Party Dialects - サードパーティのダイアレクトがSQL文のキャッシングに参加するための背景と例。

See also

SQL Compilation Caching-キャッシュシステムの概要

Object will not produce a cache key, Performance Implications-特定の構文や方言に対してキャッシングが有効になっていない場合に出力される警告の背景。

How can I profile a SQLAlchemy powered application?

パフォーマンスの問題を探すには、通常2つの方法があります。1つはクエリのプロファイリングで、もう1つはコードのプロファイリングです。

Query Profiling

単純な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() )または完全に”eager loading”機能が提供されます。 (joinedload(), subqueryload())

このアクティビティを自動化しますが、ORMの”eager loading”がなければ、一般的には結合を使用して、より多くの深さが追加されるにつれてクエリの数を増やすのではなく、複数のテーブルの結果を1つの結果セットにロードできるようにします(つまり、 r + r*r2 + r*r2*r3 …)。

クエリをより長期間にわたってプロファイルする場合や、アプリケーション側の”スロークエリ”モニタを実装する場合は、次のような方法で、イベントを使用してカーソルの実行をインターセプトできます。:

from sqlalchemy import event
from sqlalchemy.engine import Engine
import time
import logging

logging.basicConfig()
logger = logging.getLogger("myapp.sqltime")
logger.setLevel(logging.DEBUG)

@event.listens_for(Engine, "before_cursor_execute")
def before_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    conn.info.setdefault("query_start_time", []).append(time.time())
    logger.debug("Start Query: %s", statement)

@event.listens_for(Engine, "after_cursor_execute")
def after_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    total = time.time() - conn.info["query_start_time"].pop(-1)
    logger.debug("Query Complete!")
    logger.debug("Total Time: %f", total)

上記では、 ConnectionEvents.before_cursor_execute() イベントと ConnectionEvents.after_cursor_execute() イベントを使用して、文が実行される前後にインターセプトポイントを確立します。 info 辞書を使用して接続にタイマーを接続します。ここでは、カーソル実行イベントがネストされている可能性がある場合にスタックを使用します。

Code Profiling

個々のクエリに時間がかかりすぎることがログから明らかになった場合は、データベース内でクエリを処理し、結果をネットワーク経由で送信し、 DBAPI によって処理され、最終的にSQLAlchemyの結果セットやORMレイヤによって受信されるまでに費やされた時間の内訳が必要になります。これらの各ステージは、詳細に応じて、それぞれ独自のボトルネックを示すことがあります。

そのためには、 Python Profiling Module を使用する必要があります。以下は、コンテキストマネージャへのプロファイリングを行う簡単なレシピです:

import cProfile
import io
import pstats
import contextlib

@contextlib.contextmanager
def profiled():
    pr = cProfile.Profile()
    pr.enable()
    yield
    pr.disable()
    s = io.StringIO()
    ps = pstats.Stats(pr, stream=s).sort_stats("cumulative")
    ps.print_stats()
    # uncomment this to see who's calling what
    # ps.print_callers()
    print(s.getvalue())

コードのセクションをプロファイルするには:

with profiled():
    session.scalars(select(FooClass).where(FooClass.somevalue == 8)).all()

プロファイリングの出力を使用して、時間がどこに費やされているかを知ることができます。プロファイリング出力のセクションは次のようになります。

13726 function calls (13042 primitive calls) in 0.014 seconds

Ordered by: cumulative time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
222/21    0.001    0.000    0.011    0.001 lib/sqlalchemy/orm/loading.py:26(instances)
220/20    0.002    0.000    0.010    0.001 lib/sqlalchemy/orm/loading.py:327(_instance)
220/20    0.000    0.000    0.010    0.000 lib/sqlalchemy/orm/loading.py:284(populate_state)
   20    0.000    0.000    0.010    0.000 lib/sqlalchemy/orm/strategies.py:987(load_collection_from_subq)
   20    0.000    0.000    0.009    0.000 lib/sqlalchemy/orm/strategies.py:935(get)
    1    0.000    0.000    0.009    0.009 lib/sqlalchemy/orm/strategies.py:940(_load)
   21    0.000    0.000    0.008    0.000 lib/sqlalchemy/orm/strategies.py:942(<genexpr>)
    2    0.000    0.000    0.004    0.002 lib/sqlalchemy/orm/query.py:2400(__iter__)
    2    0.000    0.000    0.002    0.001 lib/sqlalchemy/orm/query.py:2414(_execute_and_instances)
    2    0.000    0.000    0.002    0.001 lib/sqlalchemy/engine/base.py:659(execute)
    2    0.000    0.000    0.002    0.001 lib/sqlalchemy/sql/elements.py:321(_execute_on_connection)
    2    0.000    0.000    0.002    0.001 lib/sqlalchemy/engine/base.py:788(_execute_clauseelement)

...

上の図では、SQLAlchemy関数の instances() が222回(再帰的に、そして外部から21回)呼び出され、すべての呼び出しを合わせて合計で.011秒かかっていることがわかります。

Execution Slowness

これらの呼び出しの詳細によって、時間がどこに費やされているかを知ることができます。例えば、DBAPIに対して、 cursor.execute() 内で費やされている時間を見ることができます。:

2    0.102    0.102    0.204    0.102 {method 'execute' of 'sqlite3.Cursor' objects}

これは、データベースが結果を返すまでに長い時間がかかっていることを示します。これは、インデックスを追加するか、クエリや基礎となるスキーマを再構築することによって、クエリを最適化する必要があることを意味します。このタスクでは、データベースバックエンドによって提供されるEXPLAIN、SHOW PLANなどのシステムを使用して、クエリ計画を分析する必要があります。

Result Fetching Slowness - Core

一方、行の取り出しに関連した呼び出しが何千回もあったり、あるいは fetchall() の呼び出しが非常に長い場合は、問い合わせが期待したよりも多くの行を返しているか、行の取り出し自体が遅いことを意味している可能性があります。ORM自体は通常、行の取り出しに fetchall() を使います( Query.yield_per() オプションが使われている場合は fetchmany() を使います)。

行の数が異常に多い場合は、DBAPIレベルでの fetchall() の呼び出しが非常に遅くなります。:

2    0.300    0.600    0.300    0.600 {method 'fetchall' of 'sqlite3.Cursor' objects}

最終的な結果が多くの行を持っていないように見えても、予期しないほど多数の行は、デカルト積の結果である可能性があります。デカルト積とは、複数の行のセットがテーブルを適切に結合せずに結合された場合です。複雑なクエリで間違った Column オブジェクトが使用され、予期しない追加のFROM句が取り込まれた場合、SQLAlchemy CoreやORMクエリでこの動作を生成するのは簡単です。

一方、DBAPIレベルでの fetchall() の呼び出しは速いですが、SQLAlchemyの CursorResult は fetchall() をするように要求されますが、ユニコード変換などのデータ型の処理が遅いことを示している可能性があります。:

# the DBAPI cursor is fast...
2    0.020    0.040    0.020    0.040 {method 'fetchall' of 'sqlite3.Cursor' objects}

...

# but SQLAlchemy's result proxy is slow, this is type-level processing
2    0.100    0.200    0.100    0.200 lib/sqlalchemy/engine/result.py:778(fetchall)

場合によっては、バックエンドが不要なタイプレベルの処理を行っている可能性があります。より具体的には、タイプAPI内の呼び出しが遅いことを確認することが、より良い指標になります。次に、このようなタイプを使用した場合の様子を示します。

from sqlalchemy import TypeDecorator import time

class Foo(TypeDecorator):

impl = String

def process_result_value(self, value, thing):

# intentionally add slowness for illustration purposes time.sleep(0.001) return value

この意図的に遅い操作のプロファイル出力は、次のようになります。:

200    0.001    0.000    0.237    0.001 lib/sqlalchemy/sql/type_api.py:911(process)
200    0.001    0.000    0.236    0.001 test.py:28(process_result_value)
200    0.235    0.001    0.235    0.001 {time.sleep}

つまり、 type_api システム内では多くの高価な呼び出しが行われますが、実際に時間がかかるのは time.sleep() 呼び出しです。

Dialect documentation をチェックして、特にOracleのようなデータベースに対して、このレベルでの既知のパフォーマンスチューニングの提案について注意してください。数値の正確さや文字列処理の保証に関連するシステムは、すべての場合に必要とされるわけではありません。

また、行フェッチのパフォーマンスが低下する低レベルのポイントがさらに存在する可能性もあります。たとえば、時間が socket.receive() のような呼び出しに集中しているように見える場合、実際のネットワーク接続を除いてすべてが高速であり、ネットワーク上を移動するデータに時間がかかりすぎていることを示している可能性があります。

Result Fetching Slowness - ORM

ORMによる行の取り出しの遅さを検出するために(これは最も一般的なパフォーマンスの問題です)、 populate_state() や _instance() のような呼び出しは、個々のORMオブジェクトの生成を示します。

# the ORM calls _instance for each ORM-loaded row it sees, and
# populate_state for each ORM-loaded row that results in the population
# of an object's attributes
220/20    0.001    0.000    0.010    0.000 lib/sqlalchemy/orm/loading.py:327(_instance)
220/20    0.000    0.000    0.009    0.000 lib/sqlalchemy/orm/loading.py:284(populate_state)

行をORMマップされたオブジェクトに変換する際のORMの遅さは、この操作の複雑さとcPythonのオーバーヘッドが組み合わさった結果です。これを緩和するための一般的な戦略には、次のようなものがあります。

  • 完全な実体ではなく、個々の列を取り出します。:

    select(User.id, User.name)

    以下の代わりに上記のようにします:

    select(User)

  • Bundle オブジェクトを使用して、列ベースの結果を整理します:

    u_b = Bundle("user", User.id, User.name)
a_b = Bundle("address", Address.id, Address.email)

for user, address in session.execute(select(u_b, a_b).join(User.addresses)):
    ...

  • 結果のキャッシュを使用します。詳細な例については Dogpile Caching を参照してください。

  • PyPyのような高速なインタープリターを考えてみてください。プロファイルの出力は少し気が遠くなりますが、少し練習すれば非常に読みやすくなります。

See also

Performance-プロファイル機能をバンドルした一連のパフォーマンスデモ。

I’m inserting 400,000 rows with the ORM and it’s really slow!

SQLAlchemy 2.0では、ほとんどの組み込みドライバが insertmanyvalues サポート付きでRETURNINGを使用するようになったため、ORM挿入の性質が変わりました。詳細は Optimized ORM bulk insert now implemented for all backends other than MySQL を参照してください。

全体的に見て、MySQL以外のSQLAlchemy組み込みドライバは、非常に高速なORMバルクインサートパフォーマンスを提供するはずです。

サードパーティのドライバは、バックエンドが必要な構文をサポートしていることを前提に、いくつかの小さなコード変更を加えて、新しいバルクインフラストラクチャにオプトインすることもできます。SQLAlchemy開発者は、サードパーティの方言のユーザに対して、これらのドライバに関する問題を投稿するよう奨励し、SQLAlchemy開発者に支援を求めることができるます。