参照カウント、循環コレクタ、そして増える行

一言でいうと

CPythonは、ほとんどのオブジェクトを参照カウントでその場で片付け、参照カウントでは片付けられない循環だけを、世代別コレクターがときどきまとめて片付けます。その「ときどき」がリクエストの真っただ中に落ちると、平均は変わらないのにp99が跳ね上がります。メモリが増え続ける問題は、「もっとも大きい行」ではなく「もっとも多く増えた行」から探す必要があります。

なぜ必要なのか

「CPU・メモリリークの見極め」コースは、プロセスの外側から、RSSとPrivate_Dirtyの傾きでリークを見つけます。その方法は「漏れている」ところまでは教えてくれますが、「どの行が」は教えてくれません。「ヒープは余っていたのにサービスが止まった」コースは、JVMのGCログで止まった時間を読みます。Pythonのサービスにも、同じ2つの問いがあります。テールレイテンシの何%がGCによるものか、そして、増え続けるメモリはソースの何行目から来ているのか。どちらも、標準ライブラリだけで、数字で答えられます。

どう動くのか

参照カウントと循環コレクター: gcモジュールのドキュメントは、このコレクターは、Pythonがすでに使っている参照カウントを補うものであり、循環参照を作らないと確信できるなら無効にしてもよい、と記しています。親が子のリストを持ち、子が親を指す木は、リクエストが終わっても、互いをつかんだままで、カウントが0になりません。このような循環だけが、コレクターの担当です。CPythonの内部ドキュメントは、コレクターは、ほかのオブジェクトを含められるコンテナオブジェクトだけを追跡すると説明しています。

世代としきい値: 同じgcのドキュメントは、オブジェクトを3つの世代に分け、最後の収集以降の割り当て数から解放数を引いた値がthreshold0を超えると、世代0から検査し、世代0の検査がthreshold1回を超えると、世代1も見ると記しています。もっとも古い世代は、内部ドキュメントが説明するように、長く生きたオブジェクトのうち、新しく入ってきた分が25%を超えたときだけ、完全な収集を行います。デフォルトのしきい値はバージョンごとに異なります。このラボのイメージ(3.12.3)でgc.get_threshold()を出力すると(700, 10, 10)が出ます。内部ドキュメントの最新版は、標準ビルドの初期値を(2000, 10, 10)と記しています。そのため、数字を暗記せず、出力して確認する必要があります。核心は、収集が「時間」ではなく「割り当て数」で引き起こされるという点です。循環を作るハンドラーは、解放なしに割り当てだけを積み上げるので、しきい値を頻繁に超えます。

収集時間の測り方: gc.callbacksに関数を入れると、収集の直前にphaseが「start」で、直後に「stop」で呼ばれ、infoには、収集した世代(generation)と回収したオブジェクト数(collected)が入ります。startとstopの間の時間が、その収集の一時停止です。これを、リクエストごとに測った遅延と並べると、「p99がなぜ跳ねたのか」に答えが出ます。用意された偽のサービスで、このPodで測ってみたところ、2万リクエストの間に、収集が300回余り(リクエストの2%ほど)動き、循環を断ち切ったハンドラーと比べて、p50は同程度なのに、p99は数倍に跳ね上がりました。1%より多くのリクエストが収集を引き受けると、そのコストがそのままp99に上がってきます。リクエスト全体の時間をGCの時間として記録すると、この因果が消えてしまいます。

gc.freeze: ドキュメントによれば、gc.freeze()は、現在追跡中のすべてのオブジェクトを永続世代に移し、以降の収集で無視します。ドキュメントが挙げる使い道は、forkの前です。親で早めにgc.disable()し、fork直前にgc.freeze()し、子で早めにgc.enable()すると、子の収集が、親から受け継いだ古いオブジェクトに触れないので、copy-on-writeによるコピーが減ります。起動時に作った大きな静的データが、収集のたびに再び走査されるコストも、一緒に消えます。

どの行が増えているのか: tracemallocは、メモリブロックが割り当てられた場所と、ファイル・行ごとの統計を提供し、2つのスナップショットの差を計算してリークを見つけられるようにしてくれます。Snapshot.compare_to(old, "lineno")は、行ごとにsize_diff(増えたバイト数)の絶対値が大きい順に並べて返します。スナップショット1つのstatistics()の一番上は「もっとも多く占めている行」なので、起動時に1回作った大きな表が先に出ます。リークは増えていくものなので、リクエストを少し流してウォームアップしてから撮り、さらに流したあとでもう一度撮って、差を見ます。フレームを多く保存するほど、tracemalloc自身のメモリとCPUの負担も大きくなると、ドキュメントは記しています。

浅いサイズの落とし穴: sys.getsizeofは、オブジェクトに直接付随するメモリだけを数え、そのオブジェクトが指すオブジェクトは数えません。辞書1つのgetsizeofは、キーと値のサイズを含まないので、コンテナ全体を知るには、公式ドキュメントがリンクしている再帰のレシピのように、たどっていきながら、同じオブジェクトを2回数えないようにする必要があります。slotsの節は、インスタンスはデフォルトで属性用の辞書を持つが、変数が数個しかないオブジェクトには無駄なので、__slots__でその領域を減らせると記しています。ところが、このPodで測ってみると、getsizeofは、むしろslotsのほうを大きく見せます。getsizeofが測るものと、実際に割り当てられるものが異なるという意味であり、そのため、比較は、tracemallocでオブジェクトを10万個作って割った値で行います。

キャッシュがリークになるとき: 二度と来ないキーで埋めるグローバルな辞書は、上限がなければ、ただのリークです。上限を設けて古いものから捨てるか、値側の参照をweakrefで持って、ほかで使われていなければ消えるようにします。weakrefのドキュメントは、弱い参照だけではオブジェクトを生かしておけず、大きなオブジェクトを入れるキャッシュが主な用途だと記しています。ただし、listとdictはそのままでは、intとtupleは継承しても、弱い参照を付けられないと記しているので、何を入れるのかを先に確認する必要があります。親ポインターのように循環を作る逆参照も、weakrefに置き換えれば、循環が消えます。

現場での姿

JVM側は「ヒープは余っていたのにサービスが止まった」コースがGCログとヒープダンプで、プロセスの外側のリークの傾きは「CPU・メモリリークの見極め」コースが扱います。イベントループのサーバーなら、GCの一時停止も、ループを止める呼び出しと同じように、すべてのリクエストを一緒に遅らせます。「遅くなったのは一つではなく全部だった」コースのループ遅延の観測が、ここでもそのまま使えます。

次のラボですること

このPodのGCのしきい値を出力し、循環を作るハンドラーが残したゴミを数えたあと、weakrefで循環を断ち切ります。gc.callbacksで収集時間を測ってp99につなげ、gc.freezeが完全な収集をどれだけ減らすかを見ます。getsizeofと深いサイズ、__slots__を比較したあと、tracemallocでリークしている行を見つけ、上限付きのキャッシュで直して、増加が消えたかを確認します。