GENIEEエンジニアブログ

株式会社ジーニーのエンジニアがアドテクノロジー・マーケティングテクノロジーなどについて情報発信するブログです。

広告配信サーバーのパフォーマンス問題を解決した話 (_raw_spin_lock_irqに関して)

はじめに

こんにちは、ジーニーR&D本部アド・プラットフォーム開発部の宮下です。

今日は弊社の開発業務で普段どんなことをしているのかな、

という業務の一旦を弊社プロダクトのGenieeDSPを例にとってご紹介したいと思います。

現象

GenieeDSPは、弊社のDSP広告配信システムでSSPから来るリクエストのうち、おおむね月間800億リクエストを処理して、広告を返しています。

ある日のこと、監視システムから、配信サーバーの一台で負荷が高まっていることを示すアラートが上がってきました。

f:id:tech-geniee:20170718175612p:plain

ジーニーでは各サーバーの稼働状況をモニタリングするものとして、Grafanaというツールを使用しています。

この時の状況でいうと、

  • CPU使用率は30%程度
  • load averageはほぼ限界まで高まっている(全てのCPUが処理待ち)という症状でした。

現象はリクエストの多い時間帯で起きており、症状の起きたサーバーではリクエストの処理能力が著しく落ち、ろくにリクエストを処理できない状態でした。

何かの処理がボトルネックになっていて配信サーバーのパフォーマンスが悪化しているものと思われました。

困った時はプロファイラ

ここで原因を特定すべく、Linuxのパフォーマンス解析ツールであるperfを使用しました。

perfは、関数別にCPU使用率を計測・表示してくれる便利なツールです。

ジーニーでは速度上のボトルネックになりそうな箇所を特定するためによく利用しているツールになります。(詳細はこちら

早速実施してみたところ、下記のような配信サーバーの関数の各使用率が表示されました。

$sudo perf top

7.55%  adserver                        [.] backend::doPreAdSelect(geniee::lot&, std::vector<geniee::banner, std::allocator<geniee::banner> >&)
5.09%  [kernel]                    [k] _raw_spin_lock_irq
4.06%  adserver                        [.] geniee::util::FastIDSet::includes(int) const
3.29%  adserver                        [.] targeting::Targeting::doIncludeTargeting(std::vector<unsigned long, std::allocator<unsigned long> > const&, std::vector<
2.87%  adserver                        [.] geniee::memory::zone(std::string const&)
2.40%  adserver                        [.] std::string::find(char const*, unsigned long, unsigned long) const

上記から見ると、案件のターゲティング処理をしている関数が重たそうなことがわかります。

しかしそれは今までも上位に来ていたので特に問題ではなさそうでした。

ここで一点、見慣れない関数が上位に表示されていました。

5.09%  [kernel]                    [k] _raw_spin_lock_irq

また、他の現象が発言していない同スペックのサーバーを調査した結果、 _raw_spin_lock_irqCPU使用率の上位に現れることはないということがわかりました。

どうやらこの関数が怪しそうです。

この関数がおそらく原因であろうという仮説のもと、より詳細に調査をすることになりました。

_raw_spin_lock_irq:ですが、これは[kernel]とperfで出力されていることからも分かるとおり、osのスケジューラ内で使用されている関数で、ある処理が、あるCPUのコアを使用している時に、他の処理からの割り込みを受けないように、変数をロックするためのものになります。

ここで、perfの機能である、その関数がどこから呼び出されてるか(callgraph)の出力をしてみます。

$perf record  -a  -- sleep 30
$perf report --stdio
               
                       |
                       --- _raw_spin_lock_irq
                          |          
                          |--49.40%--
 void std::vector<geniee::banner, std::allocator<geniee::banner> >::_M_emplace_back_aux<geniee::banner>(geniee::banner&&)
                          |          |          
                          |          |--1.55%-- 0x7fd18d0a1000
                          |          |          0x0

結果、ここでわかったのは、std::vectorに要素を追加するときに呼ばれている、ということでした。

何か自分たちで作り込んだ関数が変な処理をしていてそこが特定できればなおせるのではないか?と考えていましたが、std::vectorへの要素追加は基本的な操作なので、改善の余地はあまりないように思えました。

そこで、一旦状況を整理してみました。

  • 配信サーバーはマルチスレッドかつイベントドリブンで動いている。
  • 全スレッドはカーネルにより任意のCPUを割り当てられる。
  • あるスレッドがvectorへの要素追加をしようとすると_raw_spin_lock_irqが呼ばれ、そのCPUを使おうとする別のスレッドが処理待ちになる?のではないかと思われました。

すると、

vectorへの要素追加時に他の処理がそのCPUをそもそも使わないようにすれば良い、ように思えます。

これでいくと、各スレッドが特定のCPUのみを使用するようにすると解決しそうです。

そこでtasksetコマンドを利用して、各スレッドに一つのCPUを割り当てることにしました。

tasksetコマンドは、コマンドやプログラムを特定のコアで実行することを可能にするコマンドです。(詳細はこちら

$taskset -c -p CPUコア番号 プロセスID

というように、配信サーバーのスレッドのプロセスIDを、順々に各スレッドに対してCPUコアを割り当てていきます。

後日この現象が再発した際にサーバーにログインし、上記コマンドを実施したところ、load averageが下がり、_raw_spin_lock_irq関数がhtopの上位に来ることはほぼなくなり、なんとか事象を解決することができました。

また、この方法だとサーバーが再起動するたびに全スレッドに対してtasksetを実施しないといけないことになりそうだったので、後日配信サーバーのプログラムに1スレッドが1CPUコアを使用するように修正を行いました。

終わりに

いかがでしたでしょうか。

ジーニーでは日々増加していく膨大なリクエスト数に対して、いかにしてその処理をさばいていくのか、という課題に日夜向き合っております。

大規模なトラフィックに向き合う中で通常では遭遇しないような問題・課題もありますが、そんな時に知恵を絞って解決した時の喜びや達成感があります。

当記事でその一端をご紹介させていただきましたが、そのような課題解決に興味を持たれたり、面白そうだな、と感じていただけましたら幸いです。

ありがとうございました。