LoginSignup
28
3

Allowed memory size of *** exhausted が何のせいなのかわからない悩みを根絶やしにするため実行中の PHP プロセスのメモリ内容をぶっこぬくツールを作った

Last updated at Posted at 2023-12-02

くわしい解説

三行まとめ

  • 実行中の PHP プロセスのメモリ内容をプロセス外からぶっこ抜いて JSON で吐くツールを作った
  • Allowed memory size of *** exhausted が発生した際に起動して自身を解析させれば死んだ時の内訳もわりとわかる
  • PHP でヤベーものを作るのは楽しい

まずこいつを見てほしい

実行中の PHP スクリプトがあるとする。例えば静的解析ツールの Psalm だとしよう。

$ ps aux | grep psalm
sji      1496557  100  0.2 260524 159896 pts/0   R+   22:58   0:03 php ./psalm --no-cache --threads=1

今回紹介するツール Reli をメモリ解析モード(i:m)で Psalm の pid を指定して実行する。

sudo reli i:m -p 1496557 >1496557.memory_analyzed.json

すると作業ディレクトリに 1496557.memory_analyzed.json という怪しいファイルが出力される。jq でこれの中身をチラ見する。

$ cat 1496557.memory_analyzed.json | jq .summary

↑の出力内容が↓のようになる。

[
  {
    "zend_mm_heap_total": 551550976,
    "zend_mm_heap_usage": 318176864,
    "zend_mm_chunk_total": 543162368,
    "zend_mm_chunk_usage": 309788256,
    "zend_mm_huge_total": 8388608,
    "zend_mm_huge_usage": 8388608,
    "vm_stack_total": 262144,
    "vm_stack_usage": 22352,
    "compiler_arena_total": 2818048,
    "compiler_arena_usage": 2688448,
    "possible_allocation_overhead_total": 16711943,
    "possible_array_overhead_total": 71581552,
    "memory_get_usage": 319455472,
    "memory_get_real_usage": 551550976,
    "cached_chunks_size": 0,
    "heap_memory_analyzed_percentage": 99.59975392126012,
    "php_version": "v82",
    "analyzer": "reli 0.10.2"
  }
]

zend_mm_heap_usage というのは Reli が内訳を解析できたメモリ使用量で、memory_get_usage はこの瞬間に対象プロセスが memory_get_usage() を呼んでいたら取れたであろう値だ。zend_mm_heap_usage / memory_get_usageheap_memory_analyzed_percentage で、100% に近いほど Reli が解析できたメモリ使用量が多いことを意味する。この解析時点では 320MB 程度のメモリ消費となっているようだ。

なに、このくらいの情報ならそれこそ memory_get_usage() を呼べばほとんど足りるだろう、って?

「内訳を解析できた」 というのはその言葉通りの意味だ。jq で出力の別の部分を取り出してみよう。

$ cat 1496557.memory_analyzed.json | jq .location_types_summary

すると次のような結果が得られる。

{
  "ZendObjectMemoryLocation": {
    "count": 274030,
    "memory_usage": 79888952
  },
  "ZendArrayTableOverheadMemoryLocation": {
    "count": 366597,
    "memory_usage": 71500144
  },
  "ZendArrayTableMemoryLocation": {
    "count": 368439,
    "memory_usage": 68537880
  },
  "ZendStringMemoryLocation": {
    "count": 403267,
    "memory_usage": 37306297
  },
  "ZendArrayMemoryLocation": {
    "count": 383165,
    "memory_usage": 21457240
  },
  "ZendOpArrayBodyMemoryLocation": {
    "count": 4860,
    "memory_usage": 9986976
  },
  "ObjectsStoreMemoryLocation": {
    "count": 1,
    "memory_usage": 8388608
  },
  "ZendOpArrayHeaderMemoryLocation": {
    "count": 5156,
    "memory_usage": 1278688
  },
  "RuntimeCacheMemoryLocation": {
    "count": 3114,
    "memory_usage": 919336
  },
  "ZendReferenceMemoryLocation": {
    "count": 22047,
    "memory_usage": 705504
  },
  "ZendClassEntryMemoryLocation": {
    "count": 797,
    "memory_usage": 401688
  },
  "ZendArgInfosMemoryLocation": {
    "count": 4743,
    "memory_usage": 375744
  },
  "LocalVariableNameTableMemoryLocation": {
<以下略>

メモリ領域を用途で分類し、各用途ごとの総数と合計サイズをサイズで降順ソートして出力してる。

jq 芸と column コマンドで表に整形しつつ上位 20 件分を切り出すとこう。

$ cat 1496557.memory_analyzed.json | jq .location_types_summary | jq -r '(["location_type", "count", "memory_usage"] | (., map(length*"="))),(to_entries[]|[.key,.value.count,.value.memory_usage])|@tsv' | head -n 22 | column -t -o ' | '
location_type                           | count  | memory_usage
=============                           | =====  | ============
ZendObjectMemoryLocation                | 274030 | 79888952
ZendArrayTableOverheadMemoryLocation    | 366597 | 71500144
ZendArrayTableMemoryLocation            | 368439 | 68537880
ZendStringMemoryLocation                | 403267 | 37306297
ZendArrayMemoryLocation                 | 383165 | 21457240
ZendOpArrayBodyMemoryLocation           | 4860   | 9986976
ObjectsStoreMemoryLocation              | 1      | 8388608
ZendOpArrayHeaderMemoryLocation         | 5156   | 1278688
RuntimeCacheMemoryLocation              | 3114   | 919336
ZendReferenceMemoryLocation             | 22047  | 705504
ZendClassEntryMemoryLocation            | 797    | 401688
ZendArgInfosMemoryLocation              | 4743   | 375744
LocalVariableNameTableMemoryLocation    | 3656   | 147072
ZendPropertyInfoMemoryLocation          | 1851   | 103656
DefaultPropertiesTableMemoryLocation    | 509    | 46480
CallFrameVariableTableMemoryLocation    | 8      | 21712
ZendClassConstantMemoryLocation         | 462    | 18480
DynamicFuncDefsTableMemoryLocation      | 156    | 6544
DefaultStaticMembersTableMemoryLocation | 65     | 2192
StaticMembersTableMemoryLocation        | 43     | 1600

たとえば ZendObjectMemoryLocation は PHP スクリプト内のオブジェクト(クラスのインスタンス)に対応するメモリ領域で、この時点で 27 万 4000 個のオブジェクトが Psalm のプロセス内に存在したようだ。合計サイズは 79,888,952 で約 80MB。

ZendArrayTableOverheadMemoryLocationZendArrayTableMemoryLocation はそれぞれ配列の未使用領域とデータ部分に対応する領域で、合計すると 140MB 程度になる。何らかの配列がメモリ領域を食いまくっていることが分かる。

オブジェクトについてはクラスごとのインスタンス数やその合計サイズも出力している。次のように抽出できる。

$ cat 1496557.memory_analyzed.json | jq .class_objects_summary

以下のように出力される。これも合計サイズで降順ソートして出力している。

{
  "Psalm\\CodeLocation": {
    "count": 71399,
    "memory_usage": 29130792
  },
  "Psalm\\Type\\Union": {
    "count": 57068,
    "memory_usage": 11413600
  },
  "Psalm\\Storage\\MethodStorage": {
    "count": 10129,
    "memory_usage": 10939320
  },
  "Psalm\\Storage\\FunctionLikeParameter": {
    "count": 14653,
    "memory_usage": 5509528
  },
  "Psalm\\CodeLocation\\DocblockTypeLocation": {
    "count": 8732,
    "memory_usage": 3562656
  },
  "Psalm\\Storage\\ClassLikeStorage": {
    "count": 2343,
    "memory_usage": 3242712
  },
<以下略>

同様に jq 芸と column コマンドで表に整形しつつ上位 20 件を切り出すとこう。

$ cat 1496557.memory_analyzed.json | jq .class_objects_summary | jq -r '(["class_name", "count", "memory_usage"] | (., map(length*"="))),(to_entries[]|[.key,.value.count,.value.memory_usage])|@tsv' | head -n 22 | column -t -o ' | '
class_name                                | count | memory_usage
==========                                | ===== | ============
Psalm\\CodeLocation                       | 71399 | 29130792
Psalm\\Type\\Union                        | 57068 | 11413600
Psalm\\Storage\\MethodStorage             | 10129 | 10939320
Psalm\\Storage\\FunctionLikeParameter     | 14653 | 5509528
Psalm\\CodeLocation\\DocblockTypeLocation | 8732  | 3562656
Psalm\\Storage\\ClassLikeStorage          | 2343  | 3242712
Psalm\\Type\\Atomic\\TNamedObject         | 9968  | 1993600
Psalm\\Internal\\MethodIdentifier         | 22776 | 1639872
Psalm\\Storage\\PropertyStorage           | 3887  | 1399320
Psalm\\Type\\Atomic\\TString              | 9632  | 1155840
Psalm\\Type\\Atomic\\TArray               | 6835  | 1038920
Psalm\\Aliases                            | 4452  | 890400
Psalm\\Storage\\FileStorage               | 2240  | 878080
Psalm\\Type\\Atomic\\TMixed               | 5439  | 739704
Psalm\\Type\\Atomic\\TNull                | 5548  | 665760
Psalm\\Storage\\FunctionStorage           | 744   | 589248
Psalm\\Type\\Atomic\\TArrayKey            | 4713  | 565560
Psalm\\Type\\Atomic\\TBool                | 4128  | 495360
Psalm\\Type\\Atomic\\TInt                 | 3189  | 382680
Psalm\\Type\\Atomic\\TVoid                | 2867  | 344040

Psalm\\CodeLocation がもっとも多く、この時点で 30MB ほど食っている。

なになに、コールスタック内のローカル変数に入っているオブジェクトのプロパティの中に入っている配列の要素の値や、そのオブジェクトをスクリプト内で参照している箇所の一覧も取りたいって?

もちろん可能だ。

cat 1496557.memory_analized.json | jq '.context.call_frames[]|objects|.function_name'
"Psalm\\Internal\\Analyzer\\ClassAnalyzer::analyze"
"Psalm\\Internal\\Analyzer\\FileAnalyzer::analyze"
"Psalm\\Internal\\Codebase\\Analyzer::{closure}(/home/sji/work/oss/psalm/src/Psalm/Internal/Codebase/Analyzer.php:1581-1597)"
"Psalm\\Internal\\Codebase\\Analyzer::doAnalysis"
"Psalm\\Internal\\Codebase\\Analyzer::analyzeFiles"
"Psalm\\Internal\\Analyzer\\ProjectAnalyzer::check"
"Psalm\\Internal\\Cli\\Psalm::run"
"<main>"

これでまずコールスタック内の関数呼び出しが取得できた。Psalm\\Internal\\Analyzer\\ClassAnalyzer::analyze を解析時点で実行中だったらしい。

この関数のローカル変数の中身を 1 つ適当に取り出してみよう。

cat 1496557.memory_analized.json | jq '.context.call_frames["0"].local_variables.fq_class_name'
{
  "#reference_node_id": 202475
}

cat 1496557.memory_analized.json | jq '..|objects|select(."#node_id"==202475)|.'
{
  "#node_id": 202475,
  "#type": "StringContext",
  "#locations": [
    {
      "address": 140309542234272,
      "size": 88,
      "refcount": 8,
      "type_info": 22,
      "value": "Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer"
    }
  ]
}

実行中の関数のローカル変数 $fq_class_name には "Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer" という文字列が入っていたらしく、その参照カウントは 8。

cat 1496557.memory_analized.json | jq 'path(..|objects|select(."#reference_node_id"==202475 or ."#node_id"==202475))|join(".")'
"context.call_frames.0.this.object_properties.fq_class_name"
"context.call_frames.0.local_variables.class_context.object_properties.self"
"context.call_frames.0.local_variables.fq_class_name"
"context.call_frames.0.local_variables.class_union.object_properties.types.array_elements.Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer.key"
"context.call_frames.0.local_variables.class_union.object_properties.types.array_elements.Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer.value.object_properties.value"
"context.objects_store.615060.object_properties.types.array_elements.Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer.key"
"context.objects_store.615060.object_properties.types.array_elements.Psalm\\Internal\\Analyzer\\Statements\\Expression\\AssignmentAnalyzer.value.object_properties.value"
"context.objects_store.615060.object_properties.exact_id"

同文字列に対する 8 箇所の参照をすべて洗い出した。

出力の紹介が短く済むので文字列を使ったが、オブジェクトだろうと配列だろうとそれらのネストした構造だろうと追える。

どうだスゲーだろう。

あ、出力内容は生パスワードとかのセンシティブな情報を含む可能性もあるので、絶対にうかつにいんたーねっつへあっぷろーどしてはいけません!!!

使いみち

  • メモリリークの原因を探す
  • メモリ使用量を減らすためのメモリボトルネックを探す
  • Roadrunner などの long running な PHP 実行環境でワーカーの状態を解析して不具合の原因調査をしやすくする

なんでこんなことできるの!

  • Reli はもともと php-profiler という名前で、基本的には以前に同ツールについて解説した通り
    • 処理系の ELF バイナリを PHP で解析して拡張向けに公開されているシンボルを解決し、対象プロセスのメモリマップにもとづいて実際のアドレスを特定、FFI 経由で呼ぶ process_vm_readv() でプロセス外からコピーした上で FFI で対象 PHP バージョンの内部で使われている構造体定義にもとづいて解釈し、その中のポインタも process_vm_readv() で順次デリファレンス
  • PHP でシステムコールを呼びながら別プロセスの処理系内の構造体内容を読みつつ内部のポインタをさらに順次デリファレンスしていく仕組みはすでに作っていたので、単なるコールトレース読み取り以上にもっとたくさんの処理系内構造体の読み取りに対応すればできる
  • 処理系はスクリプトの正常な処理や不意の例外・シャットダウン発生時の各資源の破棄処理を行えるよう、何かしらの構造をポインタでつなげて各領域を管理しているので、生きている領域でさえあれば基本的にたどれるというわけ
  • とはいえ普通のやり方では解決できない部分(もはや何が普通かの基準ラインをどこに置けばいいのかわからないが)もあったので、いくつか実装上の頑張りはあり、どのような形で解析データを表すかは少し悩みもした

処理系内部状態をどう表すか

Location と Context

  • プロセスのメモリ内のどこにどんな領域があるか、は膨大な事実の羅列になる
  • プログラマーはこの情報の洪水をぶつけられても間違いなく溺れ死ぬ
  • プログラマーがメモリ使用状況を観察して改善につなげられるような情報提供を行うには、何らかの形での整理や検索集計性の担保が必要
  • コードからプログラマーが得る情報とプロセス内の各メモリ領域とを何らかの形で対応付けられるような表現が求められる

Location

location.png
  • アドレスとサイズで定まる各領域を「ここはオブジェクト用」「ここは配列のデータ部分用」といった形で Location として分類する
    • 分類には多くの場合、処理系内で使われるどの C 言語構造体と対応する領域か、という情報そのものを利用する
    • これで結果的に PHP プログラマの言語知識ともある程度の対応をつけやすくなる
  • Location で領域を分類すれば「このスクリプトでは配列の未使用領域がサイズを食っている」「どのクラスのオブジェクトが一番メモリ容量を食っているか」といった集計値を通じた分析が可能になる

Context

context.png
  • Location の羅列だけでは改善につなげる情報としてはまだ不足がある
  • 何かしらの配列が容量を食っていることが分かっても、コード上のどの配列がそれなのか、といった利用文脈の情報が分からなければ改善につなげられない
  • PHP は参照カウントを利用する言語でもあり、どの領域がどういう文脈で参照されているかという情報は重要
  • プロセス内の各領域を以下のように EG (Executor Globals) から得られるいくつかの情報起点から枝を伸ばす、ある種のツリー・グラフとして考える
    • コールスタック
    • グローバル変数一覧
    • 定義済み関数一覧
    • 定義済クラス一覧
    • 定義済定数一覧
    • 存在するオブジェクト一覧
  • これらの構造が持つポインタをひたすら再帰的にたどり続け利用文脈の枝をつなげていくことで、プロセス内でスクリプトが利用するほぼ全ての領域へ到達できる
  • このような各利用文脈を Context として分類整理しつつ、Location との対応付けを行いながら参照の枝をつなげたグラフを構築することで、「実行中の関数の呼び出し元のローカル変数 $a」「$a 内のオブジェクトのプロパティ $b」「$b と同じオブジェクトを参照する箇所の一覧」といった形で、プログラマのコード知識と紐づく形でメモリ領域の情報を提供できる
  • イメージしているのは AST のような何か(全然違うのだが)

実装上の頑張りポイント

ヒープ管理構造体の発見

zend_mm_heap.png

PHP 処理系のメモリ管理機構 ZendMM (Zend Memory Manager) では

  • リクエストごとにリセットされるメモリ領域
  • リクエストをまたいで使われるメモリ領域

の 2 種があり、PHPer が扱うほとんどの領域は前者。Reli が見ているのもそのリクエストごとにリセットされるほうのメモリ領域(なおこれらと別に opcache の SHM という領域もあるが、今回は説明を割愛)。

リクエストごとの領域すべてを管理するのに使われているのが zend_mm_heap という構造体で、処理系内では AG (Allocator Globals) というグローバル変数経由でアクセスしている。これはコールスタックの取得に使える EG (Executor Globals) とは違い公開シンボルではないため、EG と同様に処理系の ELF ファイル解析を通じて取得しようとすると普通は(普通とは……?)デバッグシンボル付きの処理系が必要となる。

利用者にデバッグシンボル付きの処理系を用意させるのは面倒なので、Reli では zend_mm_heap のアドレスを取得するために ZendMM のヒープの特徴を利用している。

ZendMM のヒープは各 2MB のチャンク単位で OS から確保され、それが更に 4KB ごとのページへ分割されて管理される。各チャンクの最初のページ先頭には zend_mm_chunk という管理用の構造体が埋め込まれていて、また各 zend_mm_chunk双方向リストでつながっている。全チャンクは通し番号を持ち、ZendMM で最初に確保される 0 番の zend_mm_chunk はメインチャンクと呼ばれ、メインチャンクの特定のオフセットには更に zend_mm_heap そのものが埋まっていて、また全ての zend_mm_chunk はこの zend_mm_heap へのポインタを持つ。

当初は phpcon2023 のスライド でも少し解説しているように、ZendMM のヒープっぽく見えるメモリ領域を /proc/<pid>/maps 経由で特定し、2MB のチャンクサイズにアラインしたアドレスを線形探索で総当りしつつ、メインチャンクに特有の構造を持つかで同定していた。

現在は EG(current_execute_data) が ZendMM のヒープ内に確保された VM スタック内のコールフレームを指すことを利用し、そのチャンクが存在するであろう zend_mm_chunk のアドレスを計算した上、デリファレンスして zend_mm_heap へのポインタを得るもう少しスマート(スマートとは?)な方法へ移行しつつある。使うのが本当に EG(current_execute_data) でよいかはまだ検討の余地があるが、基本的にはこの「公開シンボル経由で ZendMM のチャンク内にあるアドレスを見つけチャンクヘッダのアドレスを割り出してポインタをたどる」という方針で ZTS 対応も可能なはず。

ローカル変数の読み取り

vm_stack.png

VM スタックのレイアウトについては以前に phpcon 福岡で少しだけ話したことがある。あらためての作図がめんどくさいので同じ画像を使いまわす。

各コールフレームのヘッダ領域である zend_execute_datasymbol_table というフィールドをもち、これを使うとローカル変数の名前から値を引けそうな雰囲気がある。が、実際にはこれは nikic 先生が

symbol_table is a typically unused symbol table used in case some crazy person actually uses variable variables or similar features.

言っているように、頭のおかしい PHPer が可変変数みたいなクソッタレな機能を使おうとした時に実体が生えてくるもので、実は基本的にはぬるぽでいつもは存在しない。php-meminfo のような拡張はこれを Zend Engine 内の API を通じて強制的に構築することでローカル変数の読み取りを実現している。Reli ではこの手は使えないので、zend_execute_data のアドレスから引数の数や変数の数といった各種情報を計算してコールフレームのサイズを割り出し、VM スタック上のローカル変数領域(zval の配列)へ直接アクセスしている。

PHP コード上に現れる変数は CV (Compiled Variables) と呼ばれ、VM スタック上で zend_execute_data の直後に続く。上の図中で「引数領域」「コード上の変数領域」と呼んでいる部分だ。その後に処理上で使われる一時変数という見えないローカル変数のような枠として TMP / VAR 領域が別であって、これはそれぞれ非常に短命で、op_array 上のどの位置(opline)を実行しているかでどの部分が生きている値かが変わる。Zend Engine は live_ranges という構造体配列で関数(op_array)ごとにこの生存期間を管理しているので、Reli でもそれを見て有効な TMP / VAR 領域の読み取りに対応している。なお、PHP では関数呼び出し時にいくらでも余分な引数を渡すことができ、これは関数実装内から func_get_args() で取得できる。そのような余分に渡された引数もまたコールフレームの末尾へ含まれ、Reli でも読み取りに対応している。

アロケーションオーバーヘッドの計算

allocation_overhead.png

ZendMM はメモリ領域の確保に際し、以下の 3 通りで分けて扱う。

  • 3KB 以下のサイズ(small)
  • それより大きなサイズでチャンクサイズ 2MB から管理用の 1 ページ(4KB)分を除いたサイズにおさまるもの(large)
  • 通常のチャンクサイズにおさまらないもの(huge)

チャンク内の各ページがそれぞれ決まった範囲のサイズのメモリ確保を担当し、そのチャンクの中でどのページがどのあたりのサイズの確保に使われるかは、zend_mm_chunk 内にある全ページ分の管理情報から読みとれる。

small サイズの確保では各 4KB のページを更に bin と呼ばれる固定サイズの領域へ分割する。bin にはいずれも 8 の倍数で 30 通りのサイズがあり、あるページには同じサイズの bin が詰められる。メモリ確保の都度、処理系から要求されたサイズをおさめられるサイズの bin が選ばれ、bin 内の余る領域は使われない。たとえば 520 バイトのオブジェクトのためにメモリを割り当てようとすると、これを収容できるのは 640 バイトの bin で、120 バイト分が無駄になる。

large サイズの確保ではページ単位でメモリが確保されるため、処理系からの要求サイズが 4KB のページサイズの倍数と一致しない場合、余る領域は使われないことになる。たとえば 5KB のオブジェクトのためにメモリを割り当てようとすると、これを収容できるのは 2 ページ分の 8KB で、3KB 分が無駄になる。

Reli はこれらアロケーションに伴って発生するオーバーヘッドを計算し、summary の possible_allocation_overhead_total として出力している。各ページは small 用のいずれかのサイズの bin や large 用のメモリ領域を担当しており、どのアドレスがどういうサイズの確保を担当しているかは zend_mm_heap からたどれる管理情報から調べられるため、あるアドレスに何らかのサイズの領域があることを確認したら逐一そのページの管理情報を引き当てて差分を取っている。

このオーバーヘッド部分の計算は必ずしも正確ではない。例えば Reli はまだ \Closure 以外の組み込みクラスに対応しておらず、組み込みクラスはしばしば zend_object の後続領域に内部的に使う領域をまとめて確保している(ユーザ定義クラスの場合、この領域にはプロパティ用の zval 配列が入っていたりする)。後続領域を含めて収容するため ZendMM は sizeof zend_object より大きなサイズの bin を割り当てる必要があるが、現在の Reli はまだこれら内部クラスの知識を持っていないため、まるごと余剰領域に含めて計算してしまっている。内部クラス用の領域かどうかでオーバーヘッド領域の算出を別枠にした方がよいかなという気もしている。

循環参照 GC の割り切り

公開シンボルからたどれないヒープ管理領域を見つける際、利用者がデバッグシンボル付きの処理系を用意する手間を省くため、メモリチャンクの性質を使うという裏技を使った。同じく公開シンボルからたどれない構造に 循環参照 GC のルートバッファ があり、こちらでは同じ裏技が使えない。

スクリプト内で実際に利用されている領域については、コールスタックやグローバル変数などの EG からたどれる領域を起点にした Context ツリーをたどっていくことで到達できる。循環参照によって生き残っているだけの領域はこのやり方では到達できない。

循環参照は ZendMM から見るととにかく割当済の領域があるが詳細は分からないという状態であり、memory_get_usage() の集計値や memory_limit の制限へ影響を与える。現状の PHP 処理系は memory_limit 超過時には循環参照 GC を起動せず、ルートバッファの要素数が閾値を越えた場合にのみ循環参照 GC を起動するため、循環参照によるリークを解消しさえすれば memory_limit を超過しなくなるとか、手動で適切なタイミングに gc_collect_cycle() を起動すれば解消する、といった状況が時折生まれる。単なる memory_limit 超過よりひどいのは循環参照 GC とデストラクタによるリソース解放が絡み合うケースで、たとえば persistent 接続を行う PDO インスタンスが循環参照に組み込まれている状況で、同じ接続を別の PDO インスタンスが同時に掴むようなことがあるとする。PDO のデストラクタは実行中のトランザクションを自動でロールバックするため、処理系がメモリ利用状況の都合で循環参照 GC を起動した瞬間に実行中のトランザクションがロールバックされ、アプリケーションロジック上は絶対にトランザクション内で実行される筈のクエリがトランザクション外で実行されるような事故が発生し得る。よってたとえ循環参照 GC のルートバッファが得られなくとも、循環参照によってのみ生き残る領域を完全に無視するべきではない。

PHP スクリプトで循環参照を発生させ得る領域は配列とオブジェクトの 2 種類で、現実的なアプリケーションでオブジェクトがまったく関与しない循環参照が現れることはめったにない。

すべてのオブジェクトは EG からたどれる objects_store が参照カウントを増やさない形でその参照を保持する。これはスクリプトのシャットダウン時にデストラクタを確実に(順不同で)呼ぶという言語仕様を実現するための仕組みで、objects_store を Context ツリーへ含め、objects_store だけからたどれるオブジェクトを見ることで、ほとんどのケースについては循環参照によってのみ生き残っている可能性がある領域も検出できる。副産物的に、register_shutdown_function などのコールバックへ渡したクロージャなど、Reli が直接対応していない処理系内部構造が参照をつかんでいるオブジェクトについてもその存在については検出できる。

memory_limit 越え時の真のコールスタック検知

PHPer がメモリのことを気にしはじめるのは大体が memory_limit を超過したタイミングだが、memory_limit 超過時に実際に得られるスクリプトの情報は驚くほど少ない。基本的には memory_limit 超過が発生する前の最後に実行していた PHP スクリプトのファイルと行番号が得られる程度だ。コールトレースは得られないし、死んだタイミングにどこでどうメモリが使われていたかの情報も一切ない。原因を探すのはソースコードの直近の修正をしらみつぶしに探すとか、各所に memory_get_usage() を仕込んでログを増やすといった泥臭い対応になりがちだ。

memory_limit 超過は Fatal エラーであり、例外のようにはスクリプト内で catch できない。register_shutdown_function() のハンドラは起動されるため、ハンドラ内で error_get_last() で得られるメッセージを解析することで、 memory_limit 超過が起きたこと自体は検知できる。しかしここで debug_backtrace() を呼んでも、得られるコールスタックは register_shutdown_function() のハンドラを根本とするものだけで、memory_limit 超過が起きた箇所までのコールスタックは得られない。

<?php // test.php
ini_set('memory_limit', '2M');

function f() {
    $var = array_fill(0, 0x10000, 0);
    f();
}

register_shutdown_function(
    function (): void {
        $error = error_get_last();
        if (is_null($error)) {
            return;
        }
        if (strpos($error['message'], 'Allowed memory size of') !== 0) {
            return;
        }
        $pid = getmypid();
        system("sudo reli i:m -p {$pid} --no-stop-process >{$pid}_memory_analyzed.json");
    }
);

f();

このように register_shutdown_function() のハンドラ内で Reli を起動して自身の PID を渡して解析を行えば、memory_limit 超過時のスクリプトの状態をある程度は解析できるが、これも普通にやっても(普通とは……?)十分な結果は得られない。register_shutdown_function() のハンドラを起動する時点で、処理系内で現在実行中のコールフレームを保持する EG(current_execute_data) には一旦 NULL が入り、涅槃入り している。通常の形では Reli からも(スクリプト内での debug_backtrace() と同程度にしか)コールスタックを辿れなくなっていて、f() のローカル変数でのみ参照を捕捉されている $var の情報は一切得られなくなっているわけだ。

この問題には一応解決策がある。少なくとも memory_limit 超過エラー時に関しては、VM スタックそのものはまだ memory_limit 超過時の状態を保った状態で、その上に register_shutdown_function() のハンドラのコールフレームが積み上がっている。前の呼び出しへのリンクが失われているだけで、コールフレームのデータそのものは VM スタック内に生き残っている。よって、register_shutdown_function() のハンドラ内でエラー時のファイルと行番号を得た上、それらを渡しつつ Reli で自身を解析させる。シャットダウンハンドラは次のようになる。

register_shutdown_function(
    function (): void {
        $error = error_get_last();
        if (is_null($error)) {
            return;
        }
        if (strpos($error['message'], 'Allowed memory size of') !== 0) {
            return;
        }
        $pid = getmypid();
        $file_opt = '--memory-limit-error-file=' . escapeshellarg($error['file']);
        $line_opt = '--memory-limit-error-line=' . escapeshellarg($error['line']);
        system("sudo reli i:m -p {$pid} --no-stop-process {$file_opt} {$line_opt} >{$pid}_memory_analyzed.json");
    }
);

すると Reli はファイルと行番号に対応する PHP の op_array を、プロセスの関数テーブルやクラステーブルの内容を収集する際についでに見つけ出す。そして register_shutdown_function() のハンドラのコールフレームがあるアドレスから逆方向へ VM スタック上をスキャンして、先ほど見つけ出した op_array を参照しているアドレスを探し出し、そこにコールフレームが「ある」と仮定して prev_execute_data の呼び出し元コールフレームをたどり、VM スタックの根本までたどり着けるかを検証することで、memory_limit 超過時のコールスタックを復元できる。

かなり強引なやり方だが、案外きちんと動き、0.11.0 でリリースした。いくつかの OSS で実際に memory_limit 超過時の完全な情報を得られることを確認している()。とても楽しい

将来の展望

  • 無解析でメモリ内容を丸っとコピーするだけのモードの追加
    • 解析処理がまずまず重い、メモリコピーだけならそこまでではない
    • メモリダンプを後からゆっくり解析すればよい
  • RDB にデータを突っ込む機能の追加
  • よりキャッチーな可視化機能
  • より多くの内部クラスや内部構造への対応
    • まだ \Closure くらいにしか対応してない
    • 停止中の \Fiber\Generator 内の変数や例外オブジェクトのキャプチャしているトレース内容、PDO のクエリ結果など対応したい部分が色々

セキュリティ的にどうなのこれ!

  • プロセスに gdb を突き刺すのと同じ権限が必要なので、ダイジョブじゃないかな
  • root とられたらメモリ内容覗こうがファイル書き換えようがやりたい放題、それはまあそういうものなので、とられないよう気をつけて!
28
3
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
28
3