科学的観点からクラウド内のバグを検索：予期しない冒険のCEO

Stephen Wolframの投稿「 Scientific Bug Hunting in the Cloud：An Unexpected CEO Adventure」の翻訳

翻訳に協力してくれたキリル・グゼンコに深く感謝します。

Wolfram Cloudは完璧でなければなりません

Wolfram Cloudはまもなくベータテストを終了しますが、現時点ではこのシステムをできる限り良くするために多くの時間を費やしています（そして、注目に値しますが、本当にクールだとわかりました！）。 主に高レベルの機能と戦略を扱っています。 しかし、私はすべてのレベルでプロセスを制御するのが好きです。なぜなら、CEOとして、私は会社で起こるすべてのことに完全に責任があるからです。 そして、3月の初めに、私はこれまで想像もできなかった何かに没頭しました。



実際、それが私たちが話していることです。 ビジネスを含む多くの人々が使用する本格的な製造システムとして、Wolfram Cloudは可能な限り迅速に動作するはずです。 指標は速度は十分だと言っていましたが、何かが間違っていることは純粋に主観的でした。 時々、すべてが本当に高速でしたが、時には、すべてが遅すぎるように思われました。



私たちのチームには優秀なプログラマーがいますが、数ヶ月が経過し、変化は感じられませんでした。 それまでの間、Wolfram Data Dropをリリースすることができました（Habrahabrに関する記事「Wolfram Data Drop- 新しいWolfram Researchサービス」を参照）。 それでは、おそらく自分でいくつかのテストを行い、新しいWolfram Data Dropに情報を集めてみませんか？



Wolfram言語の大きな利点は、忙しい人にとってどれだけ良いかということです。たとえほんの数行のコードを印刷するだけの時間があるとしても（Habrahabrに関する記事を参照してください。 長さが140文字を超えないWolfram言語 "）を使用すると、本当に便利なものが得られます。 そして、この場合、問題を見つけるために3行のコードを調べるだけで十分でした。



まず、Wolfram CloudのシンプルなWolfram言語プログラム用のWeb APIをデプロイしました：







次に、APIを連続して50回呼び出し、そのたびに呼び出しの持続時間を測定しました（ ％は前の計算結果を表します）。







その後、時間内に一連の呼び出しを作成しました。







そして、頭に収まらない何かを手に入れました。 コールには220ミリ秒かそのような時間がかかることがありましたが、 900ミリ秒の遅延が2回検出されました。 しかし、最もクレイジーなことは、信号が量子化されているように見えることでした！



ヒストグラムを作成しました：







そして、もちろん、左側にいくつかのクイックコールがあり、中央にはかなり遅いコールがあり、右側には最も遅いコールがありました。 それは変だった！



これは常に起こるのだろうかと思いました。 そこで、 計画的なタスクを作成しました-数分ごとにAPI呼び出しを行い、Wolfram Data Dropにデータを送信します。 そして朝に戻ったとき、これは私が見たものです：







さらに奇妙な写真！ 大規模な構造はどこから来たのですか？ たとえば、クラスター内の特定のノードの速度が徐々に低下していることを理解できましたが、なぜゆっくりと回復するのですか？



最初に考えたのは、クラウドサーバーから1,000マイル以上離れているため、ネットワークの問題に遭遇したことです。 それから私はpingを見ました。 しかし、いくつかの奇妙なピークを除いて（ちょっと、インターネットです！）、すべてが非常に安定していました。

サーバー内の何かが間違っている

まあ、それはサーバー自体に何らかの問題があるに違いありません。 Wolfram Cloudにはさまざまなテクノロジーが含まれていますが、基本的にはテストしやすい純粋なWolfram言語コードです。 しかし、言語自体のレイヤーの背後には、最新のサーバーインフラストラクチャがあります。 その多くは、過去10年半にWolfram | Alphaで使用されたものとほぼ同じで、数十億の結果を出力し、過去10年間Web Mathematicaで使用されてきたものです。 しかし、もう少し厳しいコンピューティングシステムであるため、Wolfram Cloudの配置は少し異なります。



そして、私の最初の推測は、異なる設定が、Webサーバー層で何かがうまくいかない理由になる可能性があるということでした。 最終的には、インフラストラクチャ全体が純粋なWolfram言語で記述されることを望んでいますが、Javaで実行されるTomCat Webサーバーを使用する必要があります。 そして、そのようなスローダウンはJavaガベージコレクターによって引き起こされる可能性があると最初に思いました。 分析の結果、Tomcatで開始されたガベージコレクションは多少の速度低下を引き起こしましたが、それらはわずかであり、数百単位ではなくミリ秒単位で測定されました。 したがって、これは説明になりません。



私は問題を見つけることに非常に集中していました。 非常に長い間、問題やエラーの検索を深く掘り下げる必要はありませんでした。 実験科学をしているように感じました。 そして、実験科学の慣習であるように、研究の対象を可能な限り簡素化することが重要です。 したがって、「クラウドからクラウド」を管理することにより（同じクラスターからAPIを呼び出すことにより）、ほとんどのネットワーク要素を切り取りました。 次に、クラスターの特定のノードにリクエストを送信するロードバランサーを削除し、特定のノードへのリクエストをブロックします（ プライベートクラウドがない場合、サードパーティのユーザーはできません）。 ただし、遅延は依然として残っています。



その後、より詳細なデータを収集し始めました。 私の最初のステップは、Wolfram言語コードの絶対開始時間と終了時間を返すAPIを作成し、それをAPIの絶対時間と比較することでした。 そして、ここに私が見たものがあります：







青い線は、Wolfram言語コードが開始する前の時間を示しています。 金色の線は後です。 このデータは、システム全体の動作がかなり悪いときに収集しました。 初期化前の期間に深刻な減速が見られ、その後の期間にわずかな単一の減速が見られました。



そして再び-それは非常に奇妙だった。 減速が「前」または「後」の期間に特に関連しているとは思われませんでした。 それどころか、あたかもシステムの外部からランダムに何かがそれをノックアウトしたかのように。



各クラスターノードには通常8つのコアが含まれており、各コアは独自のWolfram Engineインスタンスで動作するという事実に混乱しました。 エンジンはバランスが取れており、安定しており、各インスタンスは再起動せずに何時間も、または何日も動作できます。 そして、いくつかのインスタンスに何らかのエラーが含まれているとしたらどうでしょうか？ その後、私はプロセスの IDと実行時間を追跡するAPIを構築することを決定し、たとえば、合計処理時間のAPIコンポーネントの実行時間への依存性を構築します。







実際、新しいプロセスの傾向は、より高速なAP​​I呼び出しを介して認識され始めましたが、（特にx軸上のゼロのポイントのグループ化に注目して）効果はわずかでした。

CPUの動力源は何ですか？

同じマシンで実行されている他のWolfram Cloudサービスについて考え始めました。 それらが同じ量子化されたスローダウンにつながることは理にかなっていないように思えますが、システムを簡素化するために、それらも取り除くことを望みました。 まず、本番クラスターでノードを分離しました。 それから、プライベートなWolfram Private Cloudのセットアップに取りかかりました 。 しかし、減速は残った。 異なる時期に、異なるマシンで、それらの特性はわずかに異なるように見えましたが。



プライベートクラウドでは、未加工のLinuxに移動して、周りを見回すことができました。 私が最初にしたことは、Wolfram言語のUnixユーティリティ「top」および「ps axl」から結果の収集を開始することでした。その後、それらの分析を開始しました。 そして、1つのことは非常に明白でした。多くのシステム時間が常に使い果たされ、Linuxカーネルは常に何かで忙しくしていました。 そして、実際には、スローダウンはユーザーコードによるものではないように思われました。 それらは、オペレーティングシステムのカーネルで発生する何かに由来する可能性があります。



実際、システムコールのトレースを開始しました。 過去25年ほどこのようなことはしていませんが、私の過去の経験から、大量のデータを取得できるが、解釈が難しいことが示唆されています。 ただし、Wolfram言語を自由に使用できます。



Linuxで実行中のstraceユーティリティは、API呼び出しを数秒間行い、その出力には28,221,878行が含まれていました。 ただし、特定のシステムコールの開始時間と終了時間をまとめてシステムコールの継続時間のヒストグラムを作成するのに、Wolfram言語コードの数行しか必要としませんでした。 ほんの数回のシステムコールでこれを実行すると、次のようになります。







興味深いことに、顕著な離散ピークが得られました。 そして、これらのピークに対応するシステムコールを見ると、それらはすべてfutex（スレッドの同期を担当するLinuxの一部）から来ているようです。 次に、futexからの呼び出しのみを選択し、250ミリ秒、500ミリ秒、および1000ミリ秒で鋭いピークを見ました。







しかし、彼らは本当に問題でしたか？ 実際、Futex呼び出しはアクティブではありません。 プロセッサ時間を消費しません。 そして、実際には、これは非常に典型的な状況です。I/ Oが完了するまでいくつかの呼び出しが待機している場合です。 したがって、私にとって最も興味深い点は、数百ミリ秒かかる他のシステムコールがなかったことです。

そのため、オペレーティングシステム自体の速度が低下します。

それでどうなりますか？ 私は観察し始めました-各ノードの異なるコアで何が起こっていますか？ 現在、Tomcatとインフラストラクチャの他の部分は、マルチスレッドの素晴らしい仕事をしています。 それにもかかわらず、スローダウンの原因はすべてのカーネルが異なるスレッドで動作しているにもかかわらず、すべてのカーネルを強制的にスローダウンさせることでした。 そして、これを行うことができるのは、オペレーティングシステムのカーネルだけです。



しかし、Linuxカーネルがこのような速度低下を引き起こす原因は何でしょうか？ 私はプランナーのことを考えました。 私たちの状況がスケジューラで不適切な動作を引き起こす理由を理解できませんでした。 しかし、私たちは皆スケジューラを検討し、さまざまな設定を変更しようとしました。 影響なし。

それから私はさらに見知らぬ考えを得た。 私が使用したWolfram Cloudインスタンスは、仮想マシンを介して機能しました。 しかし、「マトリックスの外側から」減速が起こった場合はどうでしょうか？ 仮想マシンなしで、Wolfram Cloudのベアメタルバージョンをリクエストしました。 しかし、提供される前に、仮想マシンでの損失に費やされた時間を測定するユーティリティを見つけましたが、無視できることが判明しました。



この時点で、私は毎日1時間か2時間この問題に対処しました。 当時、私はSXSWフェスティバルに忙しい旅行をしていました（Habrahabrの記事「 Stephen Wolfram：Frontiers of Computational Thinking（SXSWフェスティバルからのレポート） 」を参照）。 これまで、当社のクラウドソフトウェア設計チームの専門家はこの問題に積極的に関わってきましたが、私はこのタスクを彼らの熟練した手に委ねました。



戻ったとき、他の興味深い点に出会いました。 各API呼び出しを15の中間ステップに分割しました。 次に、物理学の分野で博士号を取得したエンジニアの1人が、各ステップ（左側）での減速の確率と、このステップに費やされた平均時間（右側）を比較しました。







1つの例外（既知の理由が原因）を除いて、明確な相関関係が得られました。 すべてがLinuxカーネル（およびその制御下で動作するすべてのもの）が理解できない何かの影響下にあり、完全にランダムな時間に落ちたように見え、APIの一部が呼び出されたときに非常に遅くなりました。



そして、これらの減速の原因を探し始めました。 次に気付いたのは、多数のI / O操作です。 テストした構成では、Wolfram CloudはNFSシステムを使用してファイルにアクセスしました。 NFSのプッシュ、さまざまなパラメーターの変更、非同期モードの使用、TCPの代わりにUDPの使用、NFSサーバーのI / Oスケジューラーの変更などを試みました。変更はありません。 Cephと呼ばれる完全に異なるファイルシステムを使用しようとしました。 同じ問題。 次に、ローカルディスクをメモリとして使用しようとしました。 結局、それはうまくいったように見えます-ほとんどのスローダウンは消えましたが、いくつかは残りました。



これをサインとして、I / Oエリアをさらに掘り始めました。 同じノードで多数のAPI呼び出しを起動するときに、ノードで巨大なメモ帳​​を編集する実験を実施しました。







結果は面白かった。 メモ帳が編集された（そして常に保存されていた）期間中、API呼び出しは100ミリ秒ではなく500ミリ秒続きました。 しかし、単純なファイル操作が8つのコアコアすべてに大きな影響を与えたのはなぜですか？

犯人が見つかりました

私たちはさらに掘り始め、すぐに単純なファイル操作は実際のものではないことに気付き、すぐにその理由を理解しました。 ご存知のように、約5年前、Wolfram Cloudの開発の開始時に、ファイルのバージョントラッキングを試してみたかったのです。 そして、プロトタイプとして、誰かがRCSと呼ばれる単純なバージョン管理システムを導入しました。



世界の多くのソフトウェアシステムは、ほぼ30年間にわたって重要な更新が行われていませんが、RCSを使用していますが、今でははるかに優れたソリューションがあります（ノートブックでのキャンセルの無限の可能性に使用するような） 。 しかし、何らかの理由で、同じRCSプロトタイプがWolfram Cloudコードベースで置き換えられることはなく、すべてのファイルで実行されていました！



RCSの特徴の1つは、ファイルが1ビットだけ変更された場合でも、大量のデータ（ファイル自体のサイズの数倍の場合もある）がディスクに書き込まれることです。 一般的にどのくらいのI / O操作が期待できるかはわかりませんでした。 しかし、RCSがこのプロセスを不当に強力にしたことは明らかでした。



I / O操作は実際にLinuxカーネル全体をハングさせることはできますか？ おそらく、未知のグローバルゲートウェイがあります。 おそらく、ディスクサブシステムは、完全なバッファをすぐに投入できないためにハングします。 おそらく、カーネルはメモリの大部分にアクセスできるようにするためにWebページの再レンダリングに忙しいでしょう。 あらゆることが起こる可能性がありますが、RCSを置き換えるだけで、どのような変更が生じるかを確認するだけでよいことは明らかでした。



私たちはそれをしました、そして、見よ、これらの恐ろしい減速はすぐに消えました！



そのため、1週間の集中的なデバッグの後、問題の解決策が得られました。 そして、繰り返された実験の間、すべてが正常に機能するようになりました-API呼び出しの時間は、テストクラスターへの転送時間よりも完全に優先されました。

Wolfram言語とクラウド

これは何を教えてくれましたか？ 第一に、私の印象は、これまで遭遇したことのないクラウドソフトウェア-最も困難な（敵対的でもある）開発およびデバッグ環境です。 第二に、クラウドのような複雑なシステム内で発生するすべてを分析、視覚化、整理するための一種のメタシステムとして、Wolfram言語がどれほど価値があるかを実感しました。



デバッグに関しては、この問題にやや甘やかされています-圧倒的にウォルフラム言語で書いているので、デバッグが非常に簡単で、エラーを見つけるために数分以上費やす必要はほとんどありませんでした。 Wolfram言語で簡単にデバッグできるのはなぜですか？ まず第一に、コードは通常簡潔で読みやすいためだと思います。 また、コードは通常、テストできるノートブックで記述され、プログラムの各部分は作成時に文書化されます。 もう1つの重要な詳細は、Wolfram言語はシンボリック言語であるため、いつでもプログラムのどの部分でも使用でき、独立して動作することです。



低レベルでのソフトウェアのデバッグは、まったく異なるプロセスです。 それは医療診断を行うプロセスにはるかに似ており、複雑なマルチコンポーネントシステムも処理し、いくつかの測定または実験の結果に基づいて診断を試みます（類推すると、バージョン管理の問題は何らかのひどい欠陥のように見えるかもしれませんDNA複製）。



このクラウドアドベンチャー全体は、Wolfram Cloudの価値を強調しています。 Wolfram Cloudの重要な部分は、複雑なクラウドインフラストラクチャソフトウェアのすべての問題からユーザーを保護し、Wolfram言語で直接何かを開発および展開できるようにすることです。



もちろん、これを可能にするために、自動化されたインフラストラクチャ全体を構築する必要がありました。 そして今、この「科学的アプローチによるデバッグ」の小さな冒険のおかげで、私たちはこれに一歩近づきました。 実際、これまでのところ、Wolfram Cloudには独自のAPIがあり、それは不可解な量子化されたスローダウンなしで機能し、ベータ版を完全に終了できる状態にすぐに近づきます。