Optimizing M3: How Uber Halved Our Metrics Ingestion Latency by (Briefly) Forking the Go Compiler — Part2

M3の最適化：UberがGoがコンパイをフォークすることでメトリック収集のレイテンシーを半減する方法とは — 第二章

今回の記事は長いので四回に分けて投稿しています。今回は第二回目です。

From determining what to asking why

この変更の原因を発見したてから、この変更がパフォーマンスに劇的な影響を与えた理由を特定しました。 まず、型変換が追加の割り当てを導入しているという事実や、追加の条件命題がCPUの分岐予測を混乱させているなど、変更のより明らかな側面のいくつかが問題であるかどうかを判断しました。

残念ながら、これらの理論の両方をマイクロベンチマークから瞬間的に間違っていると証明しました。 実際、ベンチマークにおいてはこれら2つの関数のパフォーマンスに目に見える違いはありませんでした。潜在的な問題として関数呼び出しのオーバーヘッドを除外しているようです。 さらに、以下の図6に示すように、新しいコードをさらに簡素化した後でも、本番環境でのデプロイメントでのリグレッションが見られました。

図6：既存のインラインコードをヘルパー関数に置き換えることにより、パフォーマンスのリグレッションをさらに絞り込むことができることがわかりました。

次にどうすればよいのか全く見当がつきませんでした。というのも、私たちは既に両方のコミットに対して比較したCPUプロファイルを持っています。そして、Clone メソッドではかかった時間に大差はありませんでした。最後の悪あがきで、それぞれ2つの実装に対するGoアセンブリを比較することにしました。 次のコマンドを実行することで、objdump を使用してプロダクションバイナリーを検査しました。

go tool objdump -S <PATH_TO_BINARY_WITH_REGRESSION> | grep /ident/identifier_pool.go -A 500

結果は以下のようになります：

2つの関数に対して生成されたアセンブリーには、レジスタ割り当てなどの微妙な違いがありましたが、cloneBytesヘルパー関数がインライン化されていないという事実を除いて、パフォーマンスに大きな影響を与える可能性のあるものに気が付きませんでした。特にマイクロベンチマークに影響を与えていないように見えるため、関数呼び出しのオーバーヘッドが問題の原因であるとは考えていませんでしたが、それは影響を与える可能性があると思われる2つの実装間における唯一の有意義な違いでした 。

cloneBytes関数のアセンブリを調べると、以下に示すように、runtime.morestack関数を呼び出していることがわかりました：

これは驚くことではありません。Goコンパイラーは、スタックを超えないことを証明できない関数に対してこれらの関数呼び出しを挿入する必要があるため（これについては後で説明します）です。しかし、前に見たruntime.morestack関数でかかった時間においての矛盾がもう一度ここで思い出されます。以下の図7に示しています：

図７：これらの２つのフレームグラフは、パフォーマンスのレグレッション（右）を示したコードのバージョンがどのようにruntime.morestack関数で大幅に多くの時間を費やしていたかを示しています。

左のフレームグラフ（図7）は、レグレッションが導入される前にruntime.morestack関数で費やされた時間を示し、右側のグラフは、その後その関数にどのくらいかかったかを示しています。 CPUプロファイルを最初に調べたとき、この矛盾を考えないようにしました。その原因は制御できないランタイムコードにあり、コントロールできなかったからです。コントロールしたCloneメソッドのパフォーマンスの違いを特定することにこだわったのです。 これは実際には大きな違いです。 リグレッションを伴うコードは、この関数で50パーセント以上の時間を費やし、CPU実行時間の74秒のうち4秒は、減速を説明するのに十分な時間です。

Orangesys.ioでは、kuberneteの運用、DevOps、監視のお手伝いをさせていただいています。ぜひ私たちにおまかせください。