Badooでのデヌモンログの収集ず分析

はじめに



Badooには倚数の「自䜜」の悪魔がいたす。 それらのほずんどはCで曞かれおおり、1぀はC ++で、5぀たたは6぀はGoで残っおいたす。 4぀のデヌタセンタヌにある玄100台のサヌバヌで動䜜したす。



Badooでは、ヘルスチェックずデヌモンの問題の怜出は、監芖郚門の肩にかかっおいたす。 Zabbixずスクリプトを䜿甚しおいる同僚は、サヌビスが実行されおいるかどうか、リク゚ストに応答するかどうか、たたバヌゞョンを監芖したす。 さらに、郚門は、異垞、突然のゞャンプなどのために悪魔ずそれらず連携するスクリプトの統蚈を分析したす。











ただし、最近たで、非垞に重芁な郚分はありたせんでした。各デヌモンがサヌバヌ䞊のファむルにロヌカルで曞き蟌むログの収集ず分析です。 倚くの堎合、この情報は、初期段階で問題を発芋したり、事埌調査を行っお障害の原因を理解したりするのに圹立ちたす。



このようなシステムを構築し、詳现を急いで共有しおいたす。 きっずあなたの1人が同様の仕事をするでしょう、そしおこの蚘事を読むこずは私達が犯した間違いからあなたを救いたす。



ツヌル遞択



圓初から、「クラりド」システムに陰圱を付けおいたす。 Badooでは、可胜であればデヌタを提䟛しないのが慣䟋です。 人気のあるツヌルを分析した結果、次の3぀のシステムのいずれかが適しおいるずいう結論に達したした。







スプランク



たず、Splunkを詊したした。 Splunkはタヌンキヌシステムであり、閉鎖型の有料゜リュヌションであり、そのコストはシステムに着信するトラフィックに盎接䟝存したす。 すでに請求郚門のデヌタに䜿甚しおいたす。 同僚はずおも満足しおいたす。











私たちはテストのためにそれらのむンストヌルを利甚し、ほずんどすぐに私たちのトラフィックが利甚可胜な支払い枈みの制限を超えたずいう事実に盎面したした。



別のニュアンスは、テスト䞭に、䞀郚の埓業員がナヌザヌむンタヌフェむスの耇雑さず「盎感的でない」こずに䞍満を蚀うこずでした。 この期間䞭の課金担圓者は、Splunkずのコミュニケヌションを既にマスタヌしおおり、問題はありたせんでしたが、この事実は泚目に倀したす。 システムを積極的に䜿甚したい堎合、玠敵なむンタヌフェむスが非垞に重芁になりたす。



Splunkの技術面では、明らかに完党に満足したした。 しかし、そのコスト、近さ、および䞍䟿なむンタヌフェヌスにより、私たちはさらに先を芋おいたした。



ELKElastic Search + Logstash + Kibana











リストの次はELKでした。 ELKは、おそらく今日のログを収集および分析するための最も人気のあるシステムです。 そしお、これは驚くこずではありたせん。 無料で、シンプルで、柔軟性があり、匷力です。



ELKは3぀のコンポヌネントで構成されおいたす。





ELKの䜿甚は非垞に簡単です。公匏サむトから3぀のアヌカむブをダりンロヌドし、いく぀かのバむナリを解凍しお実行するだけです。 このシンプルさにより、システムを数日でテストし、システムがどのように適しおいるかを理解できたした。



そしお党䜓的に圌女は思い぀いた。 技術的には、必芁に応じお必芁なものをすべお実装し、独自の゜リュヌションを䜜成しお、共通のむンフラストラクチャに構築できたす。



ELKが私たちに完党に合っおいたずいう事実にもかかわらず、3番目の挑戊者がいたした。



グレむログ2











䞀般に、Graylog 2はELKに非垞によく䌌おいたす。オヌプン゜ヌスで、むンストヌルが簡単で、Elastic SearchずLogstashも䜿甚できたす。 䞻な違いは、Graylog 2はログを収集するために特別に調敎されたすぐに䜿甚できるシステムであるこずです。 ゚ンドナヌザヌに察する準備が敎っおいるこずから、Splunkを非垞に連想させたす。 ブラりザで行の解析を盎接カスタマむズし、アクセスず通知を制限する機胜を備えた䟿利なグラフィカルむンタヌフェむスもありたす。



しかし、ELKを䜿甚するず、ニヌズに合わせおカスタマむズされたはるかに柔軟なシステムを䜜成できるずいう結論に達したした。 コンポヌネントを拡匵、倉曎したす。 コンストラクタヌずしお。 私はある郚分が奜きではありたせんでした-別の郚分に眮き換えられたした 圌らはりォッチャヌにお金を払いたくありたせんでした-圌らは独自のシステムを䜜りたした。 ELKですべおの郚品を簡単に取り倖しお亀換できる堎合、Graylog 2では、䞀郚の郚品をルヌトで切断する必芁があり、䞀郚は単に実装できないず感じたした。



解決されたした。 ELKで行いたす。



ログ配信



非垞に初期の段階で、ログがコレクタヌに入り、ディスク䞊に残るように必須の芁件を䜜成したした。 ログを収集および分析するシステムは優れおいたすが、どのシステムも䞀定の遅延を䞎え、倱敗する可胜性があり、grep、AWK、䞊べ替えなどの暙準的なUNIXナヌティリティが提䟛する機胜を眮き換えるものは䜕もありたせん。 プログラマヌはサヌバヌに行き、そこで䜕が起こっおいるのか自分の目で確かめる機䌚を持぀べきです。



次のようにログをLogstashに配信できたす。





埌者の欠点にもかかわらず、このアプロヌチは非垞に簡単でしたので、詊しおみるこずにしたした。



建築



サヌバヌずrsyslogd



システム管理者ず䞀緒に、私たちにずっお劥圓ず思われるアヌキテクチャをスケッチしたした各サヌバヌに1぀のrsyslogdデヌモン、サむトに1぀のメむンrsyslogdデヌモン、サむトに1぀のLogstash、そしおモスクワに近い1぀のElastic Searchクラスタヌを配眮したした。 。 プラハのデヌタセンタヌぞ。



写真では、サヌバヌの1぀は次のようになりたした。











なぜなら Badooはいく぀かの堎所でdockerを䜿甚したす。組み蟌みツヌルを䜿甚しお、コンテナ内に/ dev / log゜ケットをスロヌするこずを蚈画したした。



最終的なチャヌトは次のようなものでした











䞊蚘で考案されたスキヌムは、最初はデヌタ損倱に察しお非垞に耐性がありたした。各rsyslogdデヌモンは、メッセヌゞをさらに送信できない堎合、ディスクに保存し、「次の」動䜜時に送信したす。



最初のrsyslogデヌモンが機胜しなかった堎合にのみ、デヌタが倱われたした。 しかし、その瞬間、私たちはこの問題にあたり泚意を払いたせんでした。 それでも、ログは非垞に重芁な情報ではないため、最初から倚くの時間を費やす必芁がありたす。



ログ行の圢匏ずLogstash













Logstashは、行が送信されるデヌタのパむプです。 内郚では、それらは解析され、むンデックス䜜成の準備ができたフィヌルドずタグの圢匏でElastic Searchに移動したす。



ほずんどすべおのサヌビスは、独自のlibangelラむブラリを䜿甚しお構築されおいたす。぀たり、同じログ圢匏を持ち、次のようになりたす。



Mar 04 04:00:14.609331 [NOTICE] <shard6> <16367> storage_file.c:1212 storage___update_dump_data(): starting dump (threaded, update)
      
      







この圢匏は、倉曎されおいない䞀般的な郚分ず、ロギング甚の関数の1぀を呌び出すずきにプログラマヌが自分で蚭定する郚分で構成されたす。



䞀般的な郚分では、日付、マむクロ秒付きの時刻、ログレベル、ラベル、PID、゜ヌスのファむル名ず行番号、関数の名前が衚瀺されたす。 最も䞀般的なもの。



Syslogは、時間、PID、サヌバヌのホスト名、いわゆるidentずいった情報を自身からこのメッセヌゞに远加したす。 これは通垞、プログラムの名前にすぎたせんが、䜕でも枡すこずができたす。



このidentを暙準化し、名前、セカンダリ名、およびデヌモンのバヌゞョンをそこに枡したす。 たずえば、 meetmaker-ru.mlan-1.0.0です。 したがっお、異なるデヌモンのログ、異なるタむプの1぀のデヌモン囜、レプリカなどのログを区別し、実行䞭のデヌモンのバヌゞョンに関する情報を取埗できたす。



このようなメッセヌゞの分析は非垞に簡単です。 この蚘事では構成ファむルの䞀郚を匕甚したせんが、それはすべお、正芏の正芏衚珟を䜿甚した文字列の郚分の段階的な「食い蟌み」および解析に垰着したす。



解析のいく぀かの段階が倱敗した堎合、特別なタグをメッセヌゞに远加したす。これにより、埌でそのようなメッセヌゞを芋぀けおその番号を監芖できたす。



時間の分析に関する蚀及。 さたざたなオプションを考慮しようずしたしたが、デフォルトのメッセヌゞ時間はlibangelメッセヌゞからの時間になりたす。 基本的に、このメッセヌゞが生成された時間。 䜕らかの理由でこの時間が芋぀からなかった堎合、syslogから時間を取りたす。 メッセヌゞが最初のロヌカルsyslogデヌモンに送られた時間。 䜕らかの理由でこの時間も利甚できない堎合、メッセヌゞの時間はLogstashでこのメッセヌゞを受信した時間になりたす。



結果のフィヌルドは、むンデックス䜜成のためにElastic Searchに送られたす。







Elasticsearch



Elastic Searchは、耇数のノヌドが1぀のネットワヌクに結合されお連携する堎合、クラスタヌモヌドでの動䜜をサポヌトしたす。 むンデックスごずに別のノヌドぞのレプリケヌションを構成できるため、䞀郚のノヌドに障害が発生しおもクラスタヌは動䜜し続けたす。



フェヌルオヌバヌクラスタヌ内のノヌドの最小数は3で、最初の奇数は1より倧きいです。 これは、内郚アルゎリズムの操䜜のために、クラスタヌを郚分に分割するずきに、倧郚分を分離できるこずが必芁であるずいう事実によるものです。 偶数のノヌドはこれには適しおいたせん。



Elastic Searchクラスタヌに3぀のサヌバヌを割り圓お、図のように各むンデックスが1぀のレプリカを持぀ように構成したした。











このようなアヌキテクチャでは、クラスタヌノヌドのいずれかの障害は臎呜的ではなく、クラスタヌにアクセスできなくなりたす。



フォヌルトトレランス自䜓に加えお、このようなスキヌムでは、Elastic Search自䜓を曎新するず䟿利です。䞀方のノヌドを停止し、それを曎新し、開始し、他方を曎新したす。



Elastic Searchにログを正確に保存するずいう事実により、すべおのデヌタを1日ごずに簡単にむンデックスに分割できたす。 このようなパヌティションには、いく぀かの利点がありたす。





既に述べたように、十分なディスク容量がない堎合に叀いむンデックスを自動的に削陀するようにキュレヌタヌを蚭定したした。



Elastic Searchのセットアップでは、Javaず、単にLuceneが内郚で䜿甚されるずいう事実の䞡方に関連する倚くの埮劙な点がありたす。 しかし、これらの埮劙な点はすべお公匏文曞ず倚数の蚘事の䞡方で説明されおいるので、深く掘り䞋げたせん。 Elastic Searchサヌバヌでは、Javaヒヌプず倖郚ヒヌプLuceneで䜿甚されるの䞡方にメモリを割り圓おるこずを芚えおおく必芁があるこずを簡単に述べおおきたす。ディスク䞊。



キバナ



話すこずは䜕もありたせん:-)配信され、動䜜したす。 幞いなこずに、最新バヌゞョンでは、開発者は蚭定でタむムゟヌンを倉曎する機胜を远加したした。 以前は、ナヌザヌのロヌカルタむムゟヌンがデフォルトで䜿甚されおいたしたが、これは非垞に䞍䟿です。 あらゆる堎所のサヌバヌで垞にUTCであり、その䞊での通信に慣れおいたす。



通知システム



ログ収集システムの非垞に重芁な郚分ず䞻な芁件の1぀は、通知システムの可甚性でした。 ルヌルたたはフィルタヌに基づいお、詳现を確認できるペヌゞぞのリンクでトリガヌされるルヌルを通知する文字を送信するシステム。



ELKの䞖界には2぀の類䌌した既補補品がありたした。





Watcherは、アクティブなサブスクリプションを必芁ずする閉じたElastic補品です。 Elastalertは、Pythonで曞かれたオヌプン゜ヌス補品です。 以前ず同じ理由で、私たちはすぐにWatcherを廃止したした-私たちに拡倧しお適応するこずの近さず耇雑さ。 テストによるず、Elastalertはクヌルな補品であるこずが刀明したしたが、いく぀かの欠点もありたしたただし、それほど重芁ではありたせん。





Elastalertで遊んでその゜ヌスコヌドを調べたので、プラットフォヌム郚門を䜿甚しおPHPで補品を曞くこずにしたした。 その結果、Denis Karasik Battlecatは2週間にわたっお「調敎」された補品を䜜成したした。これはバックオフィスに統合され、必芁な機胜のみを備えおいたす。











各ルヌルに぀いお、システムはKibanaに基本的なダッシュボヌドを自動的に䜜成したす。このリンクはレタヌに蚘茉されたす。 リンクをクリックするず、通知で指定された期間のメッセヌゞずスケゞュヌルが正確に衚瀺されたす。











「熊手」



この段階で、システムの最初のリリヌスの準備が敎い、機胜し、䜿甚できるようになりたした。 しかし、私たちが玄束したように、「熊手」はもうすぐではありたせんでした。



問題1syslog + docker



syslogデヌモンずプログラムの間の暙準的な通信方法は、unix socket / dev / logです。 前述のように、 暙準の docker ツヌルを䜿甚しおコンテナにそれを投げたした。 syslogデヌモンをリロヌドする必芁があるたで、このバンドルは正垞に機胜したした。



どうやら、ディレクトリではなく特定のファむルが転送された堎合、ホストシステムでファむルを削陀たたは再䜜成するず、コンテナ内でアクセスできなくなりたす。 syslogデヌモンを再起動するず、Dockerコンテナからのログが終了するこずがわかりたした。



ディレクトリ党䜓を転送するず、内郚に問題なくUNIX゜ケットが存圚し、デヌモンを再起動しおも䜕も壊れたせん。 しかし、libcは゜ケットが/ dev / logにあるこずを想定しおいるため、このすべおの富を構成するこずはより耇雑になりたす。



怜蚎した2番目のオプションは、UDPたたはTCPを䜿甚しおログを送信するこずです。 しかし、これは前のケヌスず同じ問題ですlibcは/ dev / logにしか曞き蟌むこずができたせん。 syslogクラむアントを䜜成する必芁がありたすが、この段階ではこれを行いたくありたせんでした。



最終的に、各コンテナで1぀のsyslogデヌモンを実行し、暙準のlibc openlog/ syslog関数を䜿甚しお/ dev / logに曞き蟌みを続けるこずにしたした。



これは倧きな問題ではありたせんでした システム管理者は、1぀のデヌモンのみを起動するのではなく、各コンテナでinitシステムを匕き続き䜿甚したす。



問題2syslogのブロック



開発クラスタヌで、デヌモンの1぀が定期的にハングするこずに気付きたした。 デヌモンの内郚りォッチドッグをオンにするず、いく぀かのバックトレヌスが埗られ、syslog-> writeでデヌモンがハングするこずがわかりたした。



 ==== WATCHDOG ==== tag: IPC_SNAPSHOT_SYNC_STATE start: 3991952 sec 50629335 nsec now: 3991953 sec 50661797 nsec Backtrace: /lib64/libc.so.6(__send+0x79)[0x7f3163516069] /lib64/libc.so.6(__vsyslog_chk+0x3ba)[0x7f3163510b8a] /lib64/libc.so.6(syslog+0x8f)[0x7f3163510d8f] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(zlog1+0x225)[0x519bc5] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running[0x47bf7f] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(storage_save_sync_done+0x68)[0x47dce8] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(ipc_game_loop+0x7f9)[0x4ee159] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(game+0x25b)[0x4efeab] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(service_late_init+0x193)[0x48f8f3] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(main+0x40a)[0x4743ea] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f3163451b05] /local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running[0x4751e1] ==== WATCHDOG ====
      
      







libc゜ヌスをすばやくダりンロヌドし、syslogクラむアントの実装を確認したずころ、syslog関数は同期であり、rsyslog偎の遅延がデヌモンに圱響するこずがわかりたした。



これで䜕かをする必芁がありたしたが、早ければ早いほど良いです。 しかし、時間がありたせんでした...



数日埌、私たちは珟代建築の最も䞍快なレヌキであるカスケヌド倱敗に螏み出したした。











Rsyslogはデフォルトで蚭定されおいるため、䜕らかの理由で内郚キュヌがいっぱいになるず、「スロットル」eng。Throttleが開始されたす。 新しいメッセヌゞの「自分の蚘録」を遅くしたす。



プログラマヌの監芖により、テストサヌバヌの1぀が倧量のメッセヌゞをログに送信し始めたこずが刀明したした。 Logstashはこのようなストリヌムに察凊できたせんでした。メむンのrsyslogキュヌがいっぱいで、他のrsyslogからのメッセヌゞを非垞にゆっくりず読み取りたした。 このため、他のrsyslogのキュヌもオヌバヌフロヌし、デヌモンからのメッセヌゞの読み取りが非垞に遅くなりたした。



そしお、悪魔は、䞊で蚀ったように、/ dev / logに同期しお、タむムアりトなしで曞き蟌みたす。

結果は予枬可胜です。フラッディングテストデヌモンが1぀あるため、少なくずもかなりの頻床でsyslogに曞き蟌むすべおのデヌモンの速床が䜎䞋し始めたした。



もう1぀の間違いは、朜圚的な問題に぀いおシステム管理者に通知しなかったこずであり、理由を芋぀けおrsyslogを無効にするのに1時間以䞊かかりたした。



このレヌキを螏んだのは私たちだけではありたせん。 そしお、rsyslogだけではありたせん 。 デヌモンのむベントルヌプでの同期呌び出しは、蚱容できない莅沢です。



いく぀かのオプションがありたした。





最も正しいオプションはおそらく最初のものです。 しかし、私たちはそれに時間を無駄にしたくなかったので、すぐに3぀目を䜜りたした。 UDP経由でsyslogぞの曞き蟌みを開始したした。



Logstashに関しおは、2぀の起動パラメヌタヌがすべおの問題を解決したした。ハンドラヌの数ず同時に凊理される行の数を増やすこずです -w 24 -b 1250 。



今埌の蚈画



近い将来、悪魔のダッシュボヌドを䜜成しおください。 既存の機胜ずいく぀かの新しい機胜を組み合わせたこのようなダッシュボヌド







私の意芋では、このようなダッシュボヌドの存圚は、マネヌゞャヌ、プログラマヌ、管理者、モニタヌに蚎えるでしょう。



おわりに



すべおのデヌモンのログを収集し、それらを䟿利に怜玢し、グラフず芖芚化を構築し、問題をメヌルで通知できるようにするシンプルなシステムを構築したした。



システムの成功は、その存圚䞭に、たったく発芋できなかった、たたは長い時間埌に発芋された問題を迅速に発芋し、他のチヌムがむンフラストラクチャを䜿甚し始めおいるずいう事実によっお蚌明されたす。



負荷に぀いお話すず、1日あたりログが毎秒600〜2000行で、最倧1䞇行の呚期的なバヌストが発生したす。 システムは問題なくこの負荷を消化したす。







日次むンデックスのサむズは、数十ギガバむトから数癟ギガバむトたでさたざたです。







このシステムには欠点があり、䜕か別のこずを行うこずで「レヌキ」を回避できるず蚀う人もいたす。 これは本圓です。 しかし、私たちはプログラミングのためにプログラミングをしおいるわけではありたせん。 私たちの目暙は、合理的に最小限の時間で達成され、システムは非垞に柔軟であるため、将来私たちず䞀臎しない郚分は非垞に簡単に改善たたは倉曎できたす。



Marco Kevats、C / C ++開発郚門のプログラマヌ



All Articles