JMDC TECH BLOG

JMDCのエンジニアブログです

pprof で Go のパフォーマンス問題に向き合ってみた

今年、JMDCではアドベントカレンダーに参加しています。

qiita.com

本記事は、JMDC Advent Calendar 2025 13日目の記事です。


1年ほど前から Go のバックエンド開発に携わっています。プロダクト開発部の飯田です。

今回、社内向けWebアプリケーションで、「Excelファイルのダウンロード機能」のパフォーマンス問題に直面しました。データ量が1万件程度なら問題ありませんが、5万件を超えたあたりからCPU使用率にもメモリ使用量にも余裕があるのにタイムアウトエラーが発生してしまうという現象です。

すでにチーム内で対応案は検討されていましたが、苦手意識のあったパフォーマンス計測を学ぶ良い機会だと考え、Go のプロファイリングツールである pprof を使って調査することにしました。

何が起きているのか

DB からデータを取得し excelize ライブラリを使ってExcelファイルを作成・ダウンロードするAPIで、5万件のデータ出力を行うとタイムアウトエラーが発生していました。
実はこの現象の直前には、OOM (Out of Memory) によりインスタンスが落ちる事象が発生しており、その対策として改修を行い、最終的な動作確認をしている時の出来事でした。

対象は350以上のカラムを持つデータで、Excelファイル(.xlsx)のサイズにすると1万件で 12MB 近くになります。

当初の OOM の原因は、クリーンアーキテクチャの階層(インフラ、ドメイン、リポジトリ)を跨ぐたびにデータを構造体(struct)に詰め直していたことでした。これにより、5万件分のデータをメモリに展開した際、データ量の何倍ものメモリを消費していました。

その際は一時的にメモリを増強して解決しましたが、恒久的な対応としてドメインサービスを採用。データ取得からExcel作成を一貫して行い、「データを一行ずつスキャンして StreamWriter で書き込む」ことで巨大な構造体を作らない実装へ修正しました。

これにより OOM を回避することはできましたが、今度は処理が時間内に終わらずタイムアウトエラーが発生してしまいました。

pprof でブロッキングプロファイルを調査する

CloudWatch でCPU使用率とメモリ使用量を確認する

CloudWatch を確認し、CPU使用率にもメモリ使用量にも余裕があったため、DB のクエリ遅延や I/O 待ちを疑い、ブロッキングプロファイル(block)を取得することにしました。
調査には、 main.gonet/http/pprof の空の import と、ブロッキングプロファイルを有効化する記述を追加し、

import (
  // ...
  _ "net/http/pprof"
)

func main() {
  // ...
  // ブロッキングプロファイリングを有効化(調査用のため全てのイベントを記録する `1` を設定)
  runtime.SetBlockProfileRate(1)

  // 環境によってはハンドラーの登録を行う
}

APIサーバーを起動した状態で以下コマンドを使用します。

go tool pprof -http :9999 http://localhost:8080/debug/pprof/block?seconds=20

また、処理時間が件数に対して比例して増えるのかを確認するため、ローカル環境で1万件と2万件のデータを用意して比較しました。しかし、ブロッキングプロファイルの「待機時間(delay)」の傾向に大きな差は見られませんでした。

1万件データダウンロード時のブロッキングプロファイル

2万件データダウンロード時のブロッキングプロファイル

このことから、単純な比例ではなく、ある閾値を超えると急に悪化するロジックが潜んでいると予想しました。
また、インデックスは適切に張られており、プロファイルの「待機回数(contentions)」もデータ件数と一致しない小さな値だったため、N+1クエリ(1万件のデータに対して1万回 SQL を発行)の可能性も低いと判断しました。

Heapプロファイルを調査する

「一行ずつスキャンしExcelファイルに書き込む」という繰り返し処理の中で、文字列や構造体のアロケーション(メモリ確保)が大量発生し、GC が頻発。それによる Stop-the-World(全処理の一時停止)の積み重ねによりタイムアウトに至ったのではないかと推測し、Heapプロファイルの「累計メモリ確保したオブジェクト数 (alloc_objects)」を確認することにしました。

ブロッキングプロファイルと同様に、APIサーバーを起動した状態で以下コマンドを使用します。

go tool pprof -sample_index=alloc_objects -http :9999 http://localhost:8080/debug/pprof/heap?seconds=20

結果、Excelのセルに値を書き込むたびにオブジェクトのメモリ確保が行われ、累計 1431万回 ものアロケーションが発生していました。

2万件データダウンロード時の Heapプロファイル

Go では、大量のメモリ確保が発生すると、不要になったメモリを掃除するために GC が頻繁に実行されます。GC 中の Stop-the-World が積み重なることで、CPU使用率もメモリ使用量も低いまま、処理時間が異常に長くなる現象が起きていたのです。

この結果を受け、スライスの使い回しや高階関数の排除などを試みましたがアロケーションの回数はほとんど減りませんでした。
それもそのはずで、よく見るとアロケーション回数の上位にある setInlineStr(文字列書き込み)と CoordinatesToCellName(セル位置計算)は excelize ライブラリ内部で実行されている関数でした。つまり、アプリケーション側で行書き込みの関数 SetRow を呼ぶたびに、ライブラリ内部でセル単位の処理とアロケーションが大量に行われていました。

学んだことと今後の対応

ライブラリが提供している関数を見直して改善できないかと考えましたが、呼び出していたSetRow が内部でやっていたのと同じアロケーションを自分で発生させることになり得る点、また他のライブラリに変更しても確実に解決できるか分からない点から、このExcelファイルを作成する処理をAPIの同期処理で行うのではなく非同期処理(Worker)に切り替える方針としました。
また、このデータをExcelという形式で必要としている案件と5万件超のデータを扱う案件は用途が異なるため、CSV形式でもダウンロードできるようにすることを検討しています。

解決には至りませんでしたが、調査を通じて以下のような学びがありました。

  • アロケーションを減らすため、繰り返し処理ではスライスやバッファを使い回すと良い
  • 具体的な型(int, stringなど)から any 型への変換でもアロケーションが発生するため具体的な型を書いた方が良い

最後に

恒久対応を実施する前に、急遽「11万件のデータをダウンロードしたい」という要件が発生しました。

当初の OOM が発生していた一括読み込みの実装に戻せば GC 回数は減らせますが、前回の5万件と比較してデータ量が倍以上になっているため、メモリを増やしても再び OOM になるリスクが高いと判断しました。
そこで、現在の実装のまま、サーバーの設定を変更して対応することにしました。

  1. メモリを8GBへ変更(OOM 回避)
  2. タイムアウト延長(GC 遅延を許容)
  3. 環境変数 GOGC = 500 へ変更

GOGC は Go ランタイムに「GC をどのくらいの頻度で実行するか」を指示する環境変数です。デフォルトは 100 で、「今使っているヒープメモリが100%を超えたら(倍になったら)GC を実行する」設定ですが、これを 500 に上げることで、「メモリ使用量が6倍になるまで GC を待つ」設定にしました。
8GBという潤沢なメモリをバッファにし、GC の実行回数を減らすアプローチです。

この対応により、GC のオーバーヘッドが解消され、11万件のデータも無事にダウンロードすることができました。

今回は緊急対応でしたが、ベースのメモリ使用量が増えた場合の OOM リスクを考慮すると、GOMEMLIMIT でヒープ上限も合わせて設定するのがより安全だったと振り返っています。


明日14日目は、西川さんによる「医療データ基盤における入社後1年の振り返りとデータスペシャリストへの挑戦」です。お楽しみに!

JMDCでは、ヘルスケア領域の課題解決に一緒に取り組んでいただける方を積極採用中です!フロントエンド /バックエンド/ データベースエンジニア等、様々なポジションで募集をしています。詳細は下記の募集一覧からご確認ください。 hrmos.co

まずはカジュアルにJMDCメンバーと話してみたい/経験が活かせそうなポジションの話を聞いてみたい等ございましたら、下記よりエントリーいただけますと幸いです。 hrmos.co

★最新記事のお知らせはぜひ X(Twitter)、またはBlueskyをご覧ください!

x.com

bsky.app