go初心者によるcgoメモリプロファイリング改善に向けた試行錯誤

この記事は freee Engineers Advent Calendar の12日目の記事です。

こんにちは。freeeの17卒内定者でエンジニアインターンをしている @taiyo です。
これまでfreeeではRuby、サークルではPHP、卒論ではPythonと、主にスクリプト言語しか触ったことのない僕ですが、
freeeの中でgoを使った開発に携わる機会を得て触るようになり、3ヶ月前くらいからgo好きになりました。

エンジニア歴もまだ1年と3ヶ月くらいの新米ですが、後述する出来事をきっかけに
「cgoを使っているgo製のアプリケーションでC側のメモリプロファイリングをもっと手軽に出来るようにしたい気持ち」が高まったので、

• そう思うまでに至った経緯
• やってみたこと
• やってみて思ったこと

の3点について書いてみようと思います。

Go製のAPIサーバでメモリリークを発生させてしまった

事の発端はこれです。Go製APIサーバに加えた大きめな変更をリリースしたところ、数日経ってメモリリークが発生しました。
起こしてしまった...！！

先述の通り、これまでスクリプト言語ばかり触っていてメモリリークという現象に遭遇したことがなく、初めての経験だったのでめちゃくちゃ焦りました..
何からすればいいのかも分からずでしたが、あたふたしながらも助言を頂きながら進めました。

GoとCの両方でメモリリークの原因があることが判明した

結論から言うと、Go側にもC側にも原因が見つかりました。

1度目の調査

そのアプリケーションにはGoの標準ライブラリnet/http/pprofが入っていたので、
それを使ってメモリの使用状況を調べました。
調査の中で、net/http/pprofの便利さとそれが標準ライブラリとして実装されているgoの素晴らしさに、単純に「すげえ！」と声が出たのを覚えています。

結局、ここでの調査では、goのGC対象ではないcgoのCStringや、解放できていると思っていたデータが解放ができていなかったことが原因の一つであることが分かりました。

解放するコードを追加↓して、

defer C.free(unsafe.Pointer(released))

早速修正してリリース完了！これで直るはず！

...と思いきや、それでもまたメモリリークは起こりました。

2度目の調査

pprofを使って調べても原因らしき場所は見当たりませんでした。
このアプリケーションではcgoを使っていることもあり、Cのコードを調べる事にしてCの実装部分をGoと切り離してからvalgrindを入れて調査したところ、C側にリークのボトルネックになっていそうな部分が見つかりました。

そこを修正して再度リリースし、その後リークは起こらないようになったのでひとまず事態は収束しました。

僕はこう思いました

goの調査とCの調査が一緒にできるようになりたい

初めの調査でnet/http/pprofすごい！！と思いましたが、思わぬ落とし穴がありました。
net/http/pprofのプロファイリング対象は、goで割り当てられたメモリのみで、
Cの方は出力してくれないようです。

また、CやC++のメモリプロファイラでメジャーなvalgrindですが、今の所Go及びcgoではサポートしていないようで、前述した通りCのコードをGoから切り離して調査する必要がありました。

これではgoとCの調査が個別に必要になって時間がかかってしまいますし、
そんなことせず、一発でボトルネック見つけたいですよね。

net/http/pprofでC側のメモリ状況も見れるようにできるとよさそう

また同じことが起きた時に調査しやすい環境を作りたい。
net/http/pprofやっぱり便利なので、同じインターフェースで、Cのどの行でメモリを掴んでいるかが出力されるようにできるとよさそう。

cgoがあることからもgoとCの互換性は高いはずなのでどうにかできないだろうか。
ということで、色々やってみることにしました。

方針

候補に上がったのは以下の3つです。

1. GoとCのallocatorを揃える
2. net/http/pprofと同じインターフェースでGoからCのメモリプロファイルをしてくれるライブラリを作る
3. valgrindで頑張る(現状維持)

2に関してはかなり時間と腕力が必要とされると思ったので、
今回は1の「GoとCのallocatorを揃える」ことでpprofからプロファイリングできるようになるのかを調査することにフォーカスしました。

goとCのallocatorを揃えてみるという仮説

一応net/http/pprofのからソースコードを辿っていきました。
最終的にruntime/malloc.goに行き着いて、

runtime/malloc.go

// Memory allocator.
//
// This was originally based on tcmalloc, but has diverged quite a bit.
// http://goog-perftools.sourceforge.net/doc/tcmalloc.html

// The main allocator works in runs of pages.
// Small allocation sizes (up to and including 32 kB) are
// rounded to one of about 70 size classes, each of which
// has its own free set of objects of exactly that size.
// Any free page of memory can be split into a set of objects
// of one size class, which are then managed using a free bitmap.
//
// The allocator's data structures are:
//
//	fixalloc: a free-list allocator for fixed-size off-heap objects,
//		used to manage storage used by the allocator.
//	mheap: the malloc heap, managed at page (8192-byte) granularity.
//	mspan: a run of pages managed by the mheap.
//	mcentral: collects all spans of a given size class.
//	mcache: a per-P cache of mspans with free space.
//	mstats: allocation statistics.

このコメントにもあるように、goはメモリの割り当てをtcmallocをベースにしていて、Cでは通常のmallocを使っていました。
このことから、メモリ割り当てに用いるallocatorが異なるのを、同じものに揃えればうまく拾ってくれるのではないか。という仮説を置きました。

実は元々、「使っているallocatorがCとGoで違うのを合わせてみるとどうだろう」
と助言を頂いていました。が、その時は正直あまりよく分かっておらず、ここまでコードを読んでみてやっと繋がったという感じです。
ひとまず「Cのallocatorをtcmallocに合わせてみる」という仮説を検証してみます。

gperftoolsによる置き換え

malloc->tcmallocへの置き換えは、最も検索で出てくることが多く、かつgoogle製でgoとの相性のよさを期待してgperftoolsを使ってみました。
(gperftoolsに関する記事で真新しいものがなかったのが少し気になりましたが、githubのリポジトリのcommitは2016/11が最新でした。)

今回は、メモリリークを起こしていたgoアプリケーションのバージョンにgperftoolsを導入して動作確認をしました。
開発環境構築にはdockerを使ってコンテナ上で行っています。

以下は追加分のコードです。（簡略化しています）

#Dockerfile

...
RUN apt-get -y install google-perftools libgoogle-perftools-dev
...

cgo_sample.go

package main

/*
...
#cgo CFLAGS: -I/usr/include
#cgo LDFLAGS: -L/usr/lib -ltcmalloc
#include "gperftools/tcmalloc.h"
*/
import "C"
import (
  "net/http"
  _ "net/http/pprof"
);

func main() {
  http.HandleFunc("/", handler)
  http.ListenAndServe(":8800", nil)
}

func handler(w http.ResponseWriter, r *http.Request) {
  // Cでリークする処理など
}

apt-getでは、google-perftoolsとlibgoogole-perftools-devをインストールします。apt-getでインストールした二つは/usr下に入っているのでCFLAGSとLDFLAGSにそれぞれ指定します。

検証結果

$ curl http://localhost:8800
$ go tool pprof http://localhost:8800/debug/pprof/heap?debug=1
(pprof) text
5836.79kB of 5836.79kB total (  100%)
Dropped 57 nodes (cum <= 29.18kB)
Showing top 10 nodes out of 23 (cum >= 512.69kB)
      flat  flat%   sum%        cum   cum%
 2430.03kB 41.63% 41.63%  2430.03kB 41.63%  go.SomeLeakMethod1
 1334.04kB 22.86% 64.49%  1334.04kB 22.86%  go.OtherLeakMethod1
 1048.02kB 17.96% 82.44%  1048.02kB 17.96%  go.SomeLeakMethod2
  512.02kB  8.77%   100%   512.02kB  8.77%  go.OtherLeakMethod2
         0     0%   100%  1048.02kB 17.96%  go.NLeakMethod
         0     0%   100%  3764.07kB 64.49%  go.NLeakMethod2

allocatorをtcmalloccに揃えてもgoの入り口となっているgoの関数までしか表示されず、元々のpprofと同じ結果でした。
残念ながら「allocatorを揃えることでpprofで出力されるようになるのではないか」という仮説は棄却です。

注意

なお、gperftoolsの本家リポジトリにも書いてありますが、Linux-64bitではgperftoolsはうまく動いてくれないようなのでそちらも注意が必要です。
メモリ割り当て高速化のライブラリのはずなのにレスポンスが通常より1.5倍くらい遅くなってしまっていました。。
もし成功しても、導入には少しコストがかかってしまうようです。

なぜダメだったか？

• goのallocatorがtcmallocをベースにしたallocatorであり、tcmallocと全く同じものではなかったから
• cgoのプロセスがgoとは別で立ち上がっている可能性

前者はmalloc.goのコードリーディングした辺りから思っていたことです。
後者は調査しながらプロセスやスレッドについても調べてみて上がった可能性です。

なんにせよ、cgoのプロファイリング改善に向けて１つ可能性が潰れただけでも進歩はありました。

改善を目指してやってみて思ったこと

低レイヤーな部分の改善には相応な知識が必要

初体験のメモリリーク対応を通して、そういった事態への対処にはgoの言語仕様だけでなく、コンピュータサイエンスの知識まで広く求められることがよく分かりました。
今回は特にコンピュータの方ではCPUやメモリ、言語の方ではそれらを利用するための言語仕様等をインプットできましたが、同時にこれまでの自分が、先達の方々が作った便利なインターフェースをそのまま享受して深く考えずに使っていたこともよく分かりました。
まだまだ知らないことばかりであることを痛感させられ、身が引き締まる思いです。

いい意味での失敗は必要

freeeの掲げる開発文化には、「失敗して攻めよう」という項目があります。
私は、これを「1度の失敗は自分を成長させるための糧として、次同じ失敗をしないようにするために攻めの行動を取る」ことだと認識しています。

私にとってはまさに今回のメモリリーク事件に関わることがそれに当てはまると考えています。

1. 今後同じようなことでメモリリークが起こらないようにするためにはどうすればいいのか
2. メモリプロファイリングをよりスムーズに行える状況を作ることができれば積極的に実行して未然に防げるはず
3. やってみよう

課題感を持てるとモチベーションも上がってやってやるぞという気持ちになれます。
この考え方を忘れず、かつ確実に改善策を提示できるよう腕力をつけていきます。

まとめ

1. GoとCのallocatorを揃える
2. net/http/pprofと同じインターフェースでGoからCのメモリプロファイルをしてくれるライブラリを作る
3. valgrindで頑張る(現状維持)

今回1について調査しましたが、残念ながら良い結果は出ませんでした。とはいえ、GoやC疎いながらもしっかりソースコードを読んで動けたのはとてもよいきっかけになりました。
残りは2(1)案となりましたが、少し時間をかけてGoのソースコードを読みながら2に取り掛かっていきます。続報は追って更新したいと思います。

終わりになりますが、
freee株式会社では、Goなどの新しい言語、技術を用いてユーザにマジ価値を届けたい長期エンジニアインターン、エンジニア17,18卒を募集しています。
オフィスに来て弁当を食べられるお弁当制度もあります。学生の皆さんも社会人の皆さんもご興味があればぜひ、ご連絡ください。

明日は、
開発から離れて3年半。大好物は古宮のチャーシュー。今年もAdvnetCalendarに参加してもらえることになった、我らがCEO @dice-sasaki@github です！お楽しみに！