knqyf263's blog

自分のためのメモとして残しておくためのブログ。

Goで解放したメモリが少しずつ戻ってくる現象

情報を発信する人のところに情報が集まることを日々実感しているので、Linuxのメモリ管理に特に詳しいわけではないのですが最近遭遇した問題について自分の理解を書いておきます。ざっと調べても同じことを書いている人を見つけられなかったので、公開には意義があると考えています。識者の方がフィードバックをくださると嬉しいです。

※ AIの出力をベースに書いているのでいつもと少し文体が違います。

背景

Go言語で書かれたOSSアプリケーションサーバLinuxコンテナ on Kubernetesで運用していました。このサーバは主に夜間バッチでHTTPリクエストを処理するようになっています。夜間バッチ以外ではほぼ処理を行いません。通常、バッチ処理が終わってしばらくするとメモリ使用量は減少します。ですが利用しているOSSのバージョンを上げたあと、メモリ使用量がじわじわと増えていく現象が起きました。もう少し具体的には、バッチ処理後はメモリ使用量が減少しますが、しばらくすると突然増加し始め、そのまま放置するとどんどん増えていきます。

しばらくするとメモリ使用量が増えていく図

上のグラフでは、23:13頃にバッチ処理を終えたあと数分するとメモリ使用量(container_memory_usage_bytes、container_memory_rss)が減って、30分後ぐらいに急に増えています。バッチ処理のあとは何もHTTPリクエストを受け付けていないので不可解な挙動です。

要約

調査の結果、この問題の原因はLinuxカーネルの機能であるTransparent Huge Pages(THP)にあることがわかりました。特に、Go 1.21.1からランタイムにおけるTHPの扱いが変更されたことが関係しているようです。我々の環境でOSSのバージョンをアップデートした際に急に問題が発生したのは、このOSSをビルドしたGoのバージョンが上がったためでした。

GoのガベージコレクションGC)に関する公式ドキュメントには以下のような記述があります。

If you experience an increase in memory usage when upgrading to Go 1.21.1 or later, try applying this setting; it will likely resolve your issue. As an additional workaround, you can call the Prctl function with PR_SET_THP_DISABLE to disable huge pages at the process level, or you can set GODEBUG=disablethp=1 (to be added in Go 1.21.6 and Go 1.22) to disable huge pages for heap memory. Note that the GODEBUG setting may be removed in a future release.

tip.golang.org

上のドキュメント内で、いくつかの方法が紹介されています:

  1. max_ptes_none=0の設定を行う
  2. GODEBUG=disablethp=1を設定する(ただし、将来的に削除される可能性あり)
  3. PR_SET_THP_DISABLEを使ってプロセスレベルでTHPを無効にする
  4. /sys/kernel/mm/transparent_hugepage/enabledneverを設定する

どの方法を使っても、我々の環境では問題が解決することが確認できました。

THPはパフォーマンスの問題を引き起こすために多くのデータベース等で無効化が推奨されていますが(Hadoop, Redisなども)、何もアプリケーションが動作していないタイミングで勝手にメモリ使用量を増加させる事があるというのは知りませんでした。

今回はGoアプリケーションで問題が発生しましたが、根本原因はLinuxカーネルの機能であるため、C言語で書かれたアプリケーションでも発生する可能性があります。後半でC言語を使って検証しているので見てみてください。他の言語でも同様の事象は発生するはずですが、メモリアロケーターの実装によっては起きないかもしれません。

調査

以下では具体的にどのような手順でこの問題を調査していったかを時系列で書いています。結論だけ興味ある人はまとめに飛んでください。

再現の難しさ

今回の調査で一番難しかったのは問題の再現でした。本番環境のDatadogでは明らかにメモリが増加していく様子が観察されたのですが、手元の環境では再現できませんでした。

そこで以下のような様々な方法を試みました。

  • アプリケーションを単体で起動(macOS上)
  • Linux上で直接起動
  • コンテナ上で起動
  • K8s上で適当なマニフェストで起動
  • K8sでHelmチャートを使用し、本番と同じ環境・バージョンを再現

しかし、これらの方法ではどれも問題を再現できませんでした。何日も試行錯誤を重ねた末、半ば諦めていた時に偶然にも問題が再現しました。もう分からんーと思って風呂に入って戻ってきたら、突然メモリが増加していました。最初に貼ったグラフのように30分ぐらい経ってから問題が再現しました。

この偶然から、問題の再現には数十分かかることがあるということが分かりました。他の環境では数分程度で再現していたため、環境によっては長い時間待たないと再現しないということに気付いていませんでした。

Goアプリケーションの調査

手元で再現できたのでさっそく調査を開始しました。

pprofによる分析

問題がアプリケーションのバージョンアップ後に発生したことから、最初はメモリリークなどアプリケーション側の実装ミスを疑いました。そこで、Goのpprofを使用して詳細な分析を行うことにしました。

pprofの設定方法については多くの解説記事があるので、ここでは省略します。しかし、pprofの結果を見ても、アプリケーションはほとんどメモリを使用していないことが分かりました。HTTPリクエストの処理中や前後を観察しても、メモリは適切に解放されており、リークしているようには見えませんでした。

以下は、pprofで取得したメモリ使用状況の一例です:

$ go tool pprof -top http://localhost:8000/debug/pprof/heap
Fetching profile over HTTP from http://localhost:8000/debug/pprof/heap
...
Type: inuse_space
Time: Jul 18, 2024 at 8:27pm (UTC)
Showing nodes accounting for 13368.84kB, 100% of 13368.84kB total
      flat  flat%   sum%        cum   cum%
 3083.56kB 23.07% 23.07%  3083.56kB 23.07%  regexp/syntax.(*compiler).inst (inline)
 2561.48kB 19.16% 42.23%  2561.48kB 19.16%  github.com/aws/aws-sdk-go/aws/endpoints.init
  768.26kB  5.75% 47.97%   768.26kB  5.75%  go.uber.org/zap/zapcore.newCounters (inline)

inuse_space だと10-15MB程度しか使っていないと表示されています。 別途 alloc_space を確認すると確かに処理中はメモリを使用していますが、その後適切に解放されているように見えます。しかし、Linuxのpsで表示されるResident Set Size (RSS)や、docker statkubectl top、cAdvisorのcontainer_memory_usage_bytesメトリクス、などでは全て500-600MB使用していると表示されます。

もちろんGoで表示される値とこれらの値が完全に一致するとは考えていません。デマンドページングやキャッシュの影響で異なる値を表示するのは当然と考えられますが、今回はその差があまりにも大きすぎます。キャッシュを含めないRSSとの差も同様に大きいです。

GCログの調査

次に、GCのトレースログを調査しました。GODEBUG=gctrace=1を設定することでGCトレースを確認できます。もしかしたらGCが実行されるタイミングでメモリが増加しているのではないかと考えたからです。

以下はGCトレースの一例です。

GC forced
gc 4307 @1620.037s 1%: 0.13+5.5+0.005 ms clock, 1.1+0/10/0+0.043 ms cpu, 12->12->11 MB, 25 MB goal, 0 MB stacks, 1 MB globals, 8 P
GC forced
gc 4308 @1745.040s 1%: 0.14+7.4+0.010 ms clock, 1.1+0/14/0+0.080 ms cpu, 12->12->11 MB, 25 MB goal, 0 MB stacks, 1 MB globals, 8 P
GC forced
gc 4309 @1869.687s 1%: 0.15+4.9+0.005 ms clock, 1.2+0.53/9.7/0+0.045 ms cpu, 20->20->11 MB, 25 MB goal, 0 MB stacks, 1 MB globals, 8 P

GCのトレースを見ても、10-20MBしか認識されていないことが分かります。さらに、メモリ使用量が増加し始めるタイミングとGCが実行されるタイミングには相関がありませんでした。GCが全く走っていないタイミングでRSSが増加していました。

実際にはさらに多くの調査を行いましたが、これらの結果から問題はGoアプリケーション側にはなさそうだという結論に達しました。そこで、次はLinux側の調査に焦点を移すことにしました。

Linuxの調査

まず、Linuxカーネルのバージョンやオプションによって違いが出るのかを調査しました。いくつかの適当なOSディストリビューションを試してみましたが、結果は変わりませんでした。この調査は非常に時間がかかりました。というのも、メモリが増加し始めるまでに自分の手元では30分ほどかかるため、1回の検証に45-60分もかかってしまうためです。

次に、そもそもメモリのメトリクスは色々あるのですべてを精査しようと考えました。cAdvisorが返す container_memory_usage_bytes というメトリクスが具体的には何を示しているのか、他のどのようなメトリクスがあるのかについて調べました。以下がその内訳です。

container_memory_cache -- Number of bytes of page cache memory.
container_memory_rss -- Size of RSS in bytes.
container_memory_swap -- Container swap usage in bytes.
container_memory_usage_bytes -- Current memory usage in bytes,       
                                including all memory regardless of
                                when it was accessed.
container_memory_max_usage_bytes -- Maximum memory usage recorded 
                                    in bytes.
container_memory_working_set_bytes -- Current working set in bytes.
container_memory_failcnt -- Number of memory usage hits limits.
container_memory_failures_total -- Cumulative count of memory 
                                   allocation failures.

以下のブログ記事より拝借しています。

blog.freshtracks.io

このブログによると、container_memory_usage_bytesにはキャッシュ(ファイルシステムキャッシュなど)も含まれており、メモリ圧迫時に追い出される可能性のあるものも含まれています。より正確なメトリクスはcontainer_memory_working_set_bytesで、これはOOMキラーが監視しているものです。

そこで container_memory_working_set_bytescontainer_memory_rss などのメトリクスも確認してみましたが、大まかな傾向はcontainer_memory_usage_bytesと同じでした。どうやらキャッシュが大幅に増えているわけではなさそうです。

次に、コンテナが使用しているメモリの内訳を詳しく見てみることにしました。

$ stat -fc %T /sys/fs/cgroup/
tmpfs

検証環境ではcgroup v1だったため、/sys/fs/cgroup/memory/memory.statを確認しました。

$ cat /sys/fs/cgroup/memory/memory.stat
cache 6144000
rss 561676288
rss_huge 341835776
shmem 0
mapped_file 3407872
dirty 0
writeback 0
swap 0
pgpgin 6991773
pgpgout 6936421
pgfault 6998698
pgmajfault 48
inactive_anon 561647616
active_anon 4096
inactive_file 5242880
active_file 901120
unevictable 0
hierarchical_memory_limit 33652838400
hierarchical_memsw_limit 9223372036854771712
total_cache 6144000
total_rss 561676288
total_rss_huge 341835776
total_shmem 0
total_mapped_file 3407872
total_dirty 0
total_writeback 0
total_swap 0
total_pgpgin 6991773
total_pgpgout 6936421
total_pgfault 6998698
total_pgmajfault 48
total_inactive_anon 561647616
total_active_anon 4096
total_inactive_file 5242880
total_active_file 901120
total_unevictable 0

rss_hugeが多いように感じたので、差分を見ることにしました。リクエスト処理直後と30分後にメモリ使用量が増加した後で比較してみると、以下のような違いが見られました。

< cache 6098944
< rss 393728000
< rss_huge 31457280
---
> cache 6144000
> rss 561676288
> rss_huge 341835776

cache はあまり増えていませんが、 rss_hugeが約10倍に増加し、300MB以上になっています。この間、リクエストは全く受け付けていないにもかかわらず、rss_hugeが爆発的に増加しています。

この結果から、Transparent Huge Page (THP) が原因ではないかと考えました。そこで、THPを無効にしてみることにしました。具体的には /sys/kernel/mm/redhat_transparent_hugepage/enabledneverを設定しました。THPの説明に関しては日本語の文献も多いので省略します。

THPを無効にした後、この問題は再現しなくなりました。やはりTHPが原因だったようです。これにて一件落着!!!とは残念ながらなりません。なぜアプリケーションのバージョンを上げたらこの問題が起きたのか、そして何もしていないのになぜ30分ぐらいすると急にメモリ使用量が増えるのかという疑問は依然として残っていました。

Goランタイムの調査

再現するだけでかなりの時間がかかり、検証も1回の試行に時間がかかるため既に疲れていて、一旦上の調査結果で止まっていました。THPが原因っぽいけど何で急にこんなことが起きたか分からないなーとSlackで独り言を呟いていたところ、「GoとTHPの問題かも」というコメントと共に、GoのGCのドキュメントを shino さんから頂きました。

GoのGCとTHP

GoにはGCに関するドキュメントがあります。

tip.golang.org

このドキュメントには以下のような記述があります。

Set /sys/kernel/mm/transparent_hugepage/khugepaged/max_ptes_none to 0. This setting controls how many additional pages the Linux kernel daemon can allocate when trying to allocate a huge page. The default setting is maximally aggressive, and can often undo work the Go runtime does to return memory to the OS. Before Go 1.21, the Go runtime tried to mitigate the negative effects of the default setting, but it came with a CPU cost. With Go 1.21+ and Linux 6.2+, the Go runtime no longer mutates huge page state.

まさに我々が直面していた問題を説明しているようでした。さらに、参照として貼られているLinuxカーネルのBugzillaチケットのタイトルは "Pages madvise'd as MADV_DONTNEED are slowly returned to the program's RSS" となっていて「完全にこれだ...」となりました。

khugepagedの問題

以下がそのチケットです。2015年(今から9年前)に作られたものです。

bugzilla.kernel.org

このチケットの内容を要約します。

  1. 事象:

    • mmapで256MBを確保し、madviseシステムコールでMADV_DONTNEEDを渡してメモリを少しずつ解放していく
      • 正確にはmadviseという名前の通り、このシステムコールで解放すると言うよりはもう不要とカーネルに通知するだけ
      • カーネルが実際にいつ解放するかはわからないが、プロセスから見ると解放済みということで良いのかなという理解(表現が不正確だったらすみません)
    • プロセスのRSSは正しく128MBまで減少する。
    • しかし、その後放っておくと何もしていないのに少しずつメモリが増えていき256MBまで戻ってしまう。
    • 256MBまで戻る時間は環境により異なる。Amazon EC2Ubuntu 14.04だと2分程度で戻るし、ラップトップだと45分ぐらいかかるし、2時間以上かかる場合もある。
  2. 原因:

    • huge pageが増えていることがわかり、THPのデーモンであるkhugepagedが原因であることが判明。
    • madviseでDONTNEEDされたページが再びhuge pageとしてページインされるのは、Linuxカーネルのmax_ptes_noneパラメータの設定によるもの。
  3. 問題点:

    • khugepagedは通常のサイズ(普通は4KB)のページをhuge page(普通は2MB)に裏側で変換していくが、その際に解放済みの(という訳は正確ではないかもしれませんが、DONTNEEDにより不要と宣言された)隣接ページもhuge pageに変換する。
    • max_ptes_noneの値が多くのLinuxディストリビューションにおいてデフォルトで511になっているため、1ページが使用中で残る511ページが返却済みであってもhuge pageになってしまう。
    • huge pageになるとページインされ、RSSを増加させる。

完全に同じでした。メモリが元に戻っていくまでの時間が異なるのも同じ。他の環境だとすぐ戻るのに自分の手元だと全然戻らず、全然再現しないと無駄に苦しみました。

自分の理解を図にしておきます。赤いページはmadvise(..., DONTNEED)で返却されたページで、黒が使用中のページです。

赤いページの最大数を制御するのがmax_ptes_noneの値であるという理解です。デフォルトのページサイズ(4KB)のままだとするとhuge pageは512の通常ページからなるので、max_ptes_none=511というのはほぼ全てのページがDONTNEEDとマークされていてもkhugepagedがhuge pageに変換するということを意味します。どのぐらい積極的にhuge pageに変換するかを制御するパラメータ、とGoのドキュメントでは説明されています。

Goランタイムにおける回避策

この問題は、Goのランタイムにも影響を与えていました。約10年前にIssueが立てられていました。メモリを解放してもまた増えていく、という問題です。というか元々このGoのIssueで議論してから上のLinuxカーネルのBugzillaに起票したようです。

github.com

この問題の解決策として、以下のコミットが追加されていました。

github.com

madvise(..., DONTNEED)でメモリを返却してもkhugepagedがhuge pageにして戻してきてしまうので、MADV_NOHUGEPAGEを指定して勝手にhuge pageにされるのを防ぐというもの。必要なときだけMADV_HUGEPAGEを発行しているように見えます。Go 1.5からこの処理が入ったようです。

回避策の削除

Go 1.21以前のバージョンではこの回避策が実装されていましたが、この処理にはCPUコストがかかるためGo 1.21.1で削除されました。その結果、再度この事象が起こるようになりました。

つまり、THPの問題に対するGoの対応は以下のように変遷しています。

  • Go 1.5より前:問題が発生する
  • Go 1.5 - 1.21.0:問題が発生しない(回避策が実装されている)
  • Go 1.21.1以降:問題が再び発生する(回避策が削除された)

我々のケースでアプリケーションのバージョンを上げて急にこの問題が起きるようになったのは、そのアプリケーションをビルドしたGoのバージョンが異なったからでした。実際、問題の起きるソースコードをGo 1.20系でビルドしたら問題は起きなくなりました。つまりGoランタイムの変更の影響を受けていたということが確定しました。

この問題に直面していたのは我々だけではなく、Go 1.21.1以降でhuge pageが謎に増え続けるんだけど、というIssueも割と最近立っていました。

github.com

このIssueはそこそこ早めに見つけていたのですが、雑に斜め読みしたらGo 1.21.1で直ったというコメントがあったりで、自分のところのバージョンとは一致しないなーとなって最初スルーしてしまいました。しばらく経ってから再度このIssueに戻ってきてよく読んだところ、プロファイルではinuse_sizeは小さいのにプロセスのRSSは徐々に大きくなっていく、という完全に同じ問題でした。雑に読み飛ばすのは良くないなと反省し、長いですが全部を読みました。大体以下のような内容です。

  • メモリを解放してもRSSが徐々に増えていき減らない
  • アプリケーションのメモリリークを調査したが何もリークしていなかった
  • Go 1.21系で実行すると問題が起きるが、Go 1.19系で実行すると改善するので明らかにランタイムの問題だと判断した(Goのバージョン問題ともっと早く自分も気づきたかった)
  • Go 1.19ではプロファイリングの値とRSSの値に一貫性がある
  • huge pageの操作をGoランタイム側で行っていたがCPUコストが高かった
  • そもそもLinuxのhuge pageは既に複雑なので、さらにGoランタイムが独自の設定を持つことはより混乱を招くという理由で、Go 1.21.4以降ではhuge pageの操作をやめた
  • それが原因でkhugepagedが返却されたページをhuge pageに変換してしまっていた(約10年前のIssueが再燃ということ)
  • max_ptes_noneのデフォルト値が511になっているので積極的にhuge pageに変換されてしまう
  • THPを無効にするのが難しい環境もあるのでGo側で GODEBUG=disablethp=1 を追加した

10年前に問題となっていた事象と同じですね。新しい点としては、Goがhuge pageの操作をやめたので再発したという点とGoの環境変数経由でもTHPを無効にできるようになったところぐらい。このIssueを見るとGoのメンテナー含めみんな再現に苦労していました。最初は皆目見当もつかないというところから報告者がどんどん調査を進めていき、メンテナーと共に最終的に問題を特定していて美しい流れでした(こんなバグ報告者ばかりだったら良いのに…)。自分も再現には苦労しましたが仕方なさそうです。

この問題は、一部の小さいページは使用中だがその隣接するページは解放済みでなかなか使われないアプリケーションで発生しやすいと思います。要するにメモリの断片化です。Goのメンテナーから以下のようなコメントがありました。

  • アプリケーションが多くの大きな不規則なサイズのメモリ割り当て(MiBオーダー)を行い、小さなサイズの割り当てをあまり行わない場合、ヒープに永続的な穴が存在する可能性が高くなる
  • プログラムがGCサイクルの終わりまでに、長寿命の(おそらく断片化された)割り当ての間の穴を埋めるのに十分な小さな割り当てを行えば、問題にはならない

確かに常時動いているようなアプリケーションだと、ヒープ割り当ての隙間が埋まる機会が多いから発生しにくいのかもしれません。この報告者のシステムや我々のケースなど、バッチ処理で一時的にメモリ使用量が上がるが、あとはあまり動作しない場合などに起こりやすそうです。

ただ後述しますがシンプルなケースでもこの事象が再現するので、何でそもそもこんな簡単にメモリの断片化が起きるのはよく分かってないです。以下のコメントでも分からないと書いてました。

runtime: GC freeing goroutines memory but then taking it again · Issue #8832 · golang/go · GitHub

max_ptes_noneのデフォルト値について

khugepagedのこの挙動困ることが多そうだしバグなのでは?と個人的には思いましたが、みんな気付かぬうちにTHPの恩恵を受けているということで仕様と判断されています。じゃあせめてmax_ptes_none=511はアグレッシブすぎるしもっと小さい値にしたほうが良いのでは?と思ったら既に同じ議論がありました。

linux.kernel.narkive.com

  • 議論内容
    • 511は大きいから1/8ぐらいの値が良いのではないか、という提案
    • 実際Googleではmax_ptes_none = 0にして運用している
    • しかしデフォルト値を変えると影響があるユーザがあるかもしれないし、max_ptes_noneの値はユーザが変更可能なので、変更したい人はすれば良い、という回答により却下された

khugepagedにより恩恵を受けている人もいるはずだし、デフォルト値を変えるとその人達が影響を受けるという話は確かにあると思いますが、THPはDB等で無効にされがちだしどのぐらい恩恵を受けている人がいるのかは気になるところです。GoのIssueを見るとmax_ptes_none=511をやめてほしいけどLinux側の動きがない、と恨み節のようなコメントもありました。

MADV_NOHUGEPAGEをやめた理由

MADV_NOHUGEPAGEはCPUコストがかかっていたから、とドキュメントにはざっくり書いていましたが細かい話は以下のIssueで議論されていたようです。

github.com

ざっと見た感じだと、一度MADV_NOHUGEPAGEを設定してしまうとこれをクリアする方法がなく、仕方なくMADV_HUGEPAGEにしているがTHPの設定がmadviseの場合MADV_HUGEPAGEとマークされているページが対象になってしまい、stallが起きているという内容に見えます。つまりMADV_NOHUGEPAGEなどをマークする処理のCPUコストが高いと言うよりは、クリアする方法がなくMADV_HUGEPAGEにしているせいでkhugepagedの対象になり悪影響を受けるようです。ただこのIssueはちゃんと読んでないのでこの説明は間違っている可能性高いです。詳しく知りたい人は読んでみてください。

ただGoのメンテナーが「THPは既に複雑でGo側でさらに色々やるとより混乱を招くからこのゲームから降りたい」とコメントしていて、それは理解できるなと思いました。端的に言うとOSに任せるべきところはOSに任せようということですね。

調査内容まとめ

  • madvise(…, MADV_DONTNEED)でメモリの解放を繰り返し、僅かな使用中のページと隣接する解放済みのページが多数ある状況になったときに、THPによってhuge pageに変換されページインされRSSに戻ってきてしまう
  • Go 1.21.1以前はこの挙動に対する回避策を入れていたが、Go 1.21.1でそれをやめたためこの現象が起きるようになった

解決策

この問題に対しては、いくつかの解決策があります。

  1. システムレベルでの設定変更:

    • /sys/kernel/mm/transparent_hugepage/khugepaged/max_ptes_noneを0に設定する。
    • /sys/kernel/mm/transparent_hugepage/enabledneverを設定する。
  2. アプリケーションレベルでの対応:

    • GODEBUG=disablethp=1を設定する(Go 1.21.6以降で利用可能だが将来的に削除される予定)。
    • Prctl関数を使用してプロセスレベルでhuge pagesを無効にする:
   import "golang.org/x/sys/unix"

   unix.Prctl(unix.PR_SET_THP_DISABLE, 1, 0, 0, 0)

検証

せっかくなので小さいプログラムを使って検証してみます。

C言語

Bugzillaに貼ってあった以下の再現用プログラムをLinuxで動かしてみます。Ubuntu 20.04を使いました。

#include <stdio.h>
#include <stdint.h>
#include <stdlib.h>
#include <unistd.h>
#include <sys/mman.h>

void error(const char *msg) {
  printf("ERROR: %s\n", msg);
  exit(1);
}

long RSS() {
  long rss = 0;
  FILE* fp = fopen("/proc/self/statm", "r");
  if(fp == NULL)
    error("can't open statm");
  if(fscanf(fp, "%*s%ld", &rss) != 1)
    error("can't parse statm");
  fclose(fp);
  return rss * sysconf(_SC_PAGE_SIZE);
}

#define M (256<<20)
#define H (1<<21)
#define P (1<<12)

int main(int argc, char *argv[]) {
  char *p;
  int i;

  p = (char*)mmap(0, M, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
  for(i = 0; i < M; i++) {
    p[i]=i;
  }

  for(i = 0; i < M; i+=H) {
    madvise(p+i, H-P, MADV_DONTNEED);
  }

  for(i = 0; 1; i++) {
    printf("%d: %ld MB\n", i, RSS() / 1048576);
    usleep(1000000);
  }
}

変数の定義は以下です。

  • M: 256MB (メインメモリブロックのサイズ)
  • H: 2MB (ヒュージページのサイズ)
  • P: 4KB (通常のページサイズ)

main関数の動作は以下です。

  • 256MBのメモリを割り当てる(mmap使用)。
  • このメモリを1バイトずつ初期化する。
  • 2MBごとに、最後の4KBを除いてMADV_DONTNEEDを使ってmadviseする
    • これにより、ほとんどのメモリが解放されるが、各2MB区間の最後の4KBは保持される
  • 無限ループで1秒ごとにRSSを出力する

メモリレイアウトは以下のようになるはずです。

1ページだけ使用中であとの511ページが解放済みになっています。khugepagedがこれらのページを巻き込んでhuge pageにするのであれば、RSSは512倍になるはずです。

このプログラムを動かすと、最初はRSSは1MB程度になりますが、しばらく経つとどんどん増えていき、254MBに到達します。

1: 1 MB
2: 1 MB
...
570: 1 MB
571: 17 MB
...
580: 17 MB
581: 33 MB
...
600: 49 MB
601: 65 MB
...
611: 65 MB
612: 81 MB
...
693: 193 MB
694: 209 MB
...
713: 225 MB
714: 240 MB
...
723: 240 MB
724: 254 MB
...
731: 254 MB

理論的には最初は512KB残るはずでkhugepagedによって512倍の256MBになるはずですが、環境によっては少しずれるのかもしれません。今回は1MB→254MBになりました。いずれにせよプログラムで何も処理をしていないのに時間が経つと254倍ぐらいにはなってしまいます。しかも一度増えると二度と減らないです(少なくとも1時間ぐらい観測した範囲では)。こんな簡単に再現するのか...と正直かなり驚きました。

Go言語

Goでも適当に小さいプログラムを書いてみましたが、これでも再現しました。

package main

import (
        "crypto/rand"
        "fmt"
        "os"
        "strconv"
        "strings"
        "time"
)

const (
        H = 10 << 20 // 10MB
)

func RSS() uint64 {
        contents, err := os.ReadFile("/proc/self/statm")
        if err != nil {
                return 0
        }
        fields := strings.Fields(string(contents))
        if len(fields) < 2 {
                return 0
        }
        rss, err := strconv.ParseUint(fields[1], 10, 64)
        if err != nil {
                return 0
        }
        return rss * uint64(os.Getpagesize())
}

func main() {
        for i := 0; i < 1000; i++ {
                block := make([]byte, H)
                // ブロック全体をランダムな値で埋める
                if _, err := rand.Read(block); err != nil {
                        panic(err)
                }
                // blockはここでスコープを抜け、GCの対象になる
        }

        // RSSを継続的に監視
        for i := 0; ; i++ {
                fmt.Fprintf(os.Stderr, "%d: %d MB\n", i, RSS()/(1<<20))
                time.Sleep(time.Second)
        }
}

10MBぐらいの配列を適当に確保し、ランダムな値で埋める、というのを1000回ほど繰り返すだけです。for文の中で配列を確保しているので、この配列のメモリは即座に解放の対象になるはずです。

このプログラムを実行すると一旦25MBぐらいにRSSが増加しますが、しばらくすると5MBぐらいまで減り、さらにしばらく経つと増え始め10MBに到達します。

0: 25 MB
1: 25 MB
...
121: 25 MB
122: 10 MB
123: 9 MB
...
488: 5 MB
489: 5 MB
490: 6 MB
499: 6 MB
500: 9 MB
501: 9 MB
...
509: 9 MB
510: 10 MB
511: 10 MB
512: 10 MB

このときhuge pageを見ると増えていました。huge pageは以下のようにsmapsを見て計算しました。

$ awk '/AnonHugePages:/ {total += $2} END {print total / 2048}' /proc/$PID/smaps

ただ上のC言語のサンプルは明示的にメモリの断片化を引き起こしているので理解できますが、Go言語での検証に関してはただメモリを確保してすぐ解放する、という断片化が起きそうにないプログラムなのにhuge pageが増えていくのは不思議です。もちろん変数以外でもメモリを使うので綺麗に10MB分ずつ確保されるとは思っていませんが、THPによりRSSが5MB→10MBと2倍に跳ね上がるので小さくない影響があります。このプログラムでも断片化が起きるなら、上で書いた問題の起きやすいアプリケーションの条件とか関係なく、アイドリング状態の長いプログラムでは全て起こる事象なのでは...?と思い始めています。

もしかしたら何か検証間違っているかもしれないので、こちらも識者のご意見をお待ちしております。

まとめ

Transparent Huge Pages(THP)は、メモリ管理を最適化するためのLinuxカーネルの機能ですが、特定の条件下では予期せぬメモリ使用量の増加を引き起こす可能性があります。特にGo 1.21.1以降のバージョンでは、THPに関する従来の回避策が削除されたため、この問題が顕在化しやすくなっています。

この問題に直面した場合、以下の点に注意することが重要です。

  1. メモリ使用量の異常な増加が見られた場合、THPが原因である可能性を考慮する。
  2. システムの設定(特にmax_ptes_noneパラメータ)を確認し、必要に応じて調整する。
  3. アプリケーションレベルでTHPを無効にする方法を検討する。
  4. Goのバージョンによって挙動が異なる可能性があるため、バージョン変更時には注意深く監視する。

AI感満載のまとめになったので最後に自分でも少し書いておきます。

今回はとにかく再現が大変でした。やはり再現ができないバグは解決が難しいです。Goのランタイムをなかなか疑えなかったのが悔しいですが、最終的には問題の特定ができましたし諦めなければ何とかなると改めて思いました。

自分にとってのベストを尽くしましたが、理解が怪しい箇所があるので気になる人は自分でも調べてみてください。他の方の調査のきっかけとなれば幸いです。

詳しくない分野について発信することで誤情報を流していないか不安ではありますが、他人(あるいは記憶の失われた将来の自分)に説明しようとすることで理解も進むので、そういう内容こそ発信すると良いのかなと思っています(間違いだらけで良いという意味ではなく、もちろん誤りのないように最大限配慮するべきです)。ただ逆に自分の詳しい分野について、面倒になって全然書いていないのが最近の課題です。