ElasticSearch、Logstash、Kibana、Prometheusにある別のロギングシステム

すべての開発者は、アプリケーションにバグがあり、ユーザーが必要なことを実行できない状況を認識しています。 理由は異なります。ユーザーが間違ったデータを入力した、インターネット接続が遅い、などです。 ロギングシステムがなければ、これらのエラーを解析することは難しく、時には不可能です。 一方、ロギングシステムは、システム内の問題領域の優れた指標です。 私のプロジェクトでロギングシステムを構築する方法を説明します（はい）。 この記事では、Elasticsearch + Logstash + KibanaおよびPrometheusと、それらをアプリケーションに統合する方法について説明します。

2GISは、組織のWebマップおよびディレクトリです。 会社には、写真、割引、ロゴなどの追加コンテンツがある場合があります。 そして、ビジネスオーナーがこの良いものを管理するのが便利であるように、個人アカウントが作成されました。 個人アカウントを使用すると、次のことができます。

• 組織の連絡先を追加または変更する
• 写真、ロゴをアップロードする
• 組織を開いたときのユーザーの行動などを確認します。

私のアカウントは、バックエンドとフロントエンドの2つのプロジェクトで構成されています。 バックエンドは、Yii 1フレームワークを使用して、PHPバージョン5.6で記述されています（はい、はい）。 私たちは積極的にomposerを使用して、プロジェクト内の依存関係を管理し、PSR-4、名前空間、特性に従ってクラスを自動ロードします。 将来、PHPのバージョンを7にアップグレードする予定です。 NginxをWebサーバーとして使用し、データをMongoDBとPostgreSQLに保存します。 フロントエンドはJavaScriptで記述されており、 Catbeeの準備のフレームワークを使用しています。 バックエンドは、フロントエンド用のAPIを提供します。 さらにレポートでは、バックエンドについてのみ説明します。

これが統合の図です。 星空を思い出させます。 よく見ると、北斗七星が見えます。

外部サービスは異種です-それらは、独自の技術スタックとAPIを使用して、多数のチームによって開発されます。 統合シナリオは非自明です-最初に1つのサービスに行き、データを取得し、ビジネスロジックを課し、新しいデータでさらにいくつかのサービスに行き、答えを組み合わせてフロントエンドに結果を与えます。 また、ユーザーが問題を抱えており、たとえば広告キャンペーンを延長するなどの目的を達成できない場合、ロギングシステムがないと問題の場所を把握できません-データを外部サービスに誤って送信するか、回答を誤って解釈するか、外部サービスが利用できないか、誤ってビジネスロジックを課します。

エラーログがありましたが、新しいサービスの出現により、統合を追跡し、新たな問題に関する技術サポートリクエストに対応することがますます困難になりました。 そのため、ログシステムの新しい要件を開発しました。

• エラーに関するより多くのコンテキストが必要です-何が発生し、どのユーザーでしたか。
• 便利な方法で着信リクエストを収集します。
• メソッドが長時間応答する場合は、チームに通知する必要があります。

エラーログ

歴史的に、当社はログを収集して表示するために、 Elasticsearch + Logstash + Kibanaテクノロジースタック（略してELK）を使用しています。 Elasticsearch-全文検索機能を備えたNoSQLドキュメントリポジトリ。 Logstashは、TCP / UDPプロトコルを介してログを受信し、Redisからメッセージを読み取り、Elasticsearchに保存するように構成されています。 Kibanaは、収集されたデータを検索および表示するための視覚的なインターフェースを提供します。

クライアントで何か問題が発生した場合、彼は問題の説明とともにアカウントからテクニカルサポートに連絡します。 エラーロギングがありましたが、ユーザーのメール、APIメソッドの呼び出し、呼び出しスタックはありませんでした。 メッセージには、「リクエストが誤った結果を返しました」という形式の未処理の例外からの行のみがありました。 このため、クライアントが連絡した時間とキーワードで問題を検索しましたが、これは必ずしも正確ではありませんでした-クライアントは1日で連絡を取ることができ、支援するのは非常に困難でした。

苦痛の後、私たちは何かをする必要があると判断し、必要な情報を追加しました-ユーザーのメール、APIメソッド、リクエスト本文、コールスタック、リクエストを処理したコントローラーとアクション。 その結果、テクニカルサポートと私たち自身の生活を簡素化しました-ユーザーのメールを割引し、ログエントリを見つけて問題に対処します。 どのユーザーが問題を起こしたか、どのメソッドが呼び出されたか、そしてコードのどの部分がそれを処理したかを正確に把握しています。 流通時期による比較なし！

アプリケーションがグレイログ拡張ログ形式（略してGELF）でUDPで実行されているときにエラーメッセージを送信します。 この形式は、一般的なアルゴリズムでメッセージを圧縮して部分に分割できるため、アプリケーションからLogstashに送信されるトラフィックの量を減らすことができる点で優れています。 UDPプロトコルはメッセージ配信を保証しませんが、応答時間に最小限のオーバーヘッドを課すため、このオプションが適しています。 アプリケーションでは、 gelf-phpライブラリを使用します。これは、さまざまな形式とプロトコルでログを送信する機能を提供します。 PHPアプリケーションで使用することをお勧めします。

結論-アプリケーションが外部ユーザーと連携し、新たな技術サポートの質問への回答を探す必要がある場合は、クライアントとそのアクションを識別するのに役立つ情報を自由に追加してください。
メッセージの例：

{ "user_email": "test@test.ru", "api_method": "orgs/124345/edit", "method_type": "POST", "payload": "{'name': ' '}", "controller": "branches/update", "message": "Undefined index: 'name' File: /var/www/protected/controllers/BranchesController.php Line: 50" } 

ロギングのリクエスト

構造化された形式のリクエストのロギングと統計情報の収集がなかったため、どのメソッドが最も頻繁に呼び出され、どのくらい応答したかは明確ではありませんでした。 これにより、次のことができませんでした。

• メソッドの許容可能な応答時間を推定します。
• ブレーキの原因は、私たちの側にあるのか、外部サービスの側にあるのか（星空のスキームを覚えていますか？）
• どうすればコードを最適化して応答時間を短縮できますか。

このタスクの一環として、次の問題を解決する必要がありました。

1. ロギング用の応答パラメーターの選択
2. パラメーターをLogstashに送信する

Nginx Webサーバーを使用し、アクセスログをファイルに書き込むことができます。 最初の問題を解決するために、構成にログを保存するための新しい形式が示されました。

 log_format main_logstash '{' '"time_local": "$time_local",' '"request_method": "$request_method",' '"request_uri": "$request_uri",' '"request_time": "$request_time",' '"upstream_response_time": "$upstream_response_time",' '"status": "$status",' '"request_id": "$request_id"' '}'; server { access_log /var/log/nginx/access.log main_logstash; } 

ほとんどのメトリックは、質問を提起するものではないと思います。最も興味深いもの、$ request_idについて詳しく説明します。 これは、リクエストごとにNginxによって生成される一意の識別子、バージョン4 UUIDです。 リクエスト内のこのヘッダーを外部サービスに転送し、他のサービスのログでリクエストの応答を追跡できます。 他のサービスの問題を検索するときに非常に便利です-時間の比較はありません、呼び出されたメソッドのURL。

Logstashにログを送信するには、 Beaverユーティリティを使用します。 ログを送信する予定のすべてのアプリケーションノードにインストールされます。 構成は、新しいログを受信するために解析されるファイルを示し、各メッセージとともに送信されるフィールドが示されます。 メッセージはRedisクラスターに送信され、そこからLogstashがデータを収集します。 Beaverの設定は次のとおりです。

 [/var/log/nginx/access.log] type: nginx_accesslog add_field: team,lk,project,backend tags: nginx_json 

Logstashのフィールドをタイプおよびタグ付けすることにより、値に応じて、ログのフィルタリングと処理が行われたため、これらの値を独自のものにすることができます。 さらに、チームとプロジェクトのフィールドを追加して、ログが属するチームとプロジェクトを識別できるようにします。

アクセスログを収集することを学んだので、SLAメソッドの定義に進みました。 サービス提供のレベルに関する合意であるSLAは、この場合、メソッドの応答時間の95パーセンタイルが0.4秒以下であることを保証します。 許容時間に収まらない場合、アプリケーションのいずれかの統合が遅くなり、関連するチームに向かうか、コードに何らかの問題があり、最適化が必要であることを意味します。

アクセスログの収集に関する結論-最も頻繁に呼び出されるメソッドとそれらの許容可能な応答時間を決定しました。

以下は、測定されたメソッドの1つに関するレポートの例です。 最初-応答時間と平均応答時間の50、95、99パーセンタイルは何ですか：

応答ステータスチャート：

一定期間の平均応答時間：

SLAチームアラート

ログを収集した後、速度の低下についてすぐに調べる必要があるという考えが得られました。 Kibanaでブラウザを常に開いたままにし、F5を押して、95パーセンタイルの現在の値と有効な値を比較することは、あまり実用的ではないことが判明しました。 したがって、アラートを生成するために、Prometheusシステムとの統合を追加しました。 Prometheusは、実行中のアプリケーションのメトリックを収集、保存、分析するためのオープンソースシステムです。 ドキュメントのある公式サイト 。

トリガーが発生した場合、電子メールでアラートを送信できるという点で、システムが気に入りました。 この機会は、サーバーへのアクセスに問題がなく、アラートを生成するカスタムスクリプトを記述することなく、すぐに使用できます。 システムはGoで記述されており、作成者はSoundCloudです。 Go、PHP、Python、Lua、C＃、Erlang、Haskellなど、さまざまな言語でメトリックを収集するためのライブラリがあります。

Prometheusをインストールして実行する方法については説明しません。 これに興味があれば、 記事を読むことをお勧めします 。 私たちにとって実際に重要なポイントに焦点を当てます。

統合スキームは次のようになります。アドレスのクライアントアプリケーションは一連のメトリックを提供し、Prometheusはこのアドレスに移動して、リポジトリのメトリックを取得して保存します。

メトリックがどのように見えるか見てみましょう。

1. 名前は、調査対象の特性の識別子です。 たとえば、着信リクエストの数。
2. 一度のメトリックには特定の意味があります。 メトリックを収集するとき、時間がプロメテウスを下ろします。
3. メトリックにはラベルを付けることができます。 収集された数に関する追加情報が含まれています。 この例は、アプリケーションノードとAPIメソッドを示しています。 ラベルの主な機能は、ラベルを検索して必要なデータサンプルを作成できることです。

時間値形式のデータストアは、時系列データベースと呼ばれます。 これは、時変メトリックを格納するための高度に専門化されたNoSQLリポジトリです。 たとえば、サイトの午前10時、1日、1週間などのユーザー数。 解決されるタスクの詳細とストレージ方法により、このようなデータベースは高性能でコンパクトなデータストレージを提供します。

Prometheusは、いくつかのタイプのメトリックをサポートしています。 Counterと呼ばれる最初のタイプを検討してください。 新しい測定のカウンターの値は常に大きくなります。 履歴全体の着信リクエストの総数を測定するのに理想的です-今日では合計リクエストが100で、明日は80に減少することはできません。

しかし、応答時間の測定はどうでしょうか？ それは必ずしも成長するわけではなく、さらに、落ちてしばらくの間一定のレベルになり、その後成長する可能性があります。 変更は10秒未満で発生する可能性があり、各リクエストの応答時間を変更するダイナミクスを確認したいと考えています。 幸いなことに、ヒストグラムのタイプがあります。 形成のために、応答時間を測定する間隔を決定する必要があります。 この例では、0.1〜0.5秒かかります。これらはすべてInfinityと見なされます。

ヒストグラムの初期状態は次のとおりです。

 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.1"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.2"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.3"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.4"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.5"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="+Inf"} 0 api_request_time_sum{node="api1.2gis.com",handler="/users"} 0 api_request_time_count{node="api1.2gis.com",handler="/users"} 0 

間隔の値ごとに、特定のルールに従ってカウンターを作成します。

1. 名前には_bucket接尾辞が含まれている必要があります
2. 間隔の値を示すファイルラベルが必要です。 さらに、値が+ Infのカウンターが必要です。
3. 接尾辞_sumおよび_countを持つカウンターが必要です。 すべての応答の合計時間とリクエストの数を保存します。 Prometheusツールを使用した95パーセンタイルの便利な計算に必要です。

ヒストグラムを応答時間で正しく埋める方法を考えてみましょう。 これを行うには、ラベルleの値が応答時間以上であるシリーズを見つけ、それらを1増やします。 メソッドが0.4秒で応答したとします。 ラベルleが0.4以上のカウンターを見つけ、値に1を追加します。

 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.1"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.2"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.3"} 0 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.4"} 1 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.5"} 1 api_request_time_bucket{node="api1.2gis.com",handler="/users",le="+Inf"} 1 api_request_time_sum{node="api1.2gis.com",handler="/users"} 0.4 api_request_time_count{node="api1.2gis.com",handler="/users"} 1 

メソッドが0.1秒を担当する場合、すべてのシリーズを増やします。 0.6秒の責任がある場合は、値「+ Inf」でのみカウンタを増やします。 カウンターapi_request_time_sumおよびapi_request_time_countを増やすことを忘れないでください。 ヒストグラムを使用して、応答時間を測定できます。応答時間は、多くの場合短期間で変化します。

Prometheusは、スケールと結果の概要という2つのタイプのメトリックをサポートしています。 スケールは、値が増減できる特性を表します。 このような指標はわが国では測定されないため、タスクでは使用しません。 結果の概要は、アプリケーション側で計算された分位を保存する高度なヒストグラムです。 理論的には、95パーセンタイル、つまり0.95分位を計算することは可能ですが、これにより、クライアント側でカウントコードが追加され、レポートの柔軟性が失われます。計算された分位のみを使用できます。 したがって、彼らはヒストグラムを選択しました。

Lua言語のNginxでヒストグラム生成を実装しました。 GitHubで完成したプロジェクトを見つけました。これは、Nginx構成で接続され、上記の方法でヒストグラムを生成します。 最も頻繁に呼び出されるメソッドからデータを収集する必要があります。これは、覚えているとおり、Logstashにアクセスログを送信した後に決定しました。 そのため、要求をログに記録する必要があるかどうかを確認するビジネスロジックを追加する必要がありました。

その結果、プロメテウスの材料とLua言語の基礎の研究に加えて、統合に1週間かかりました。 私たちの意見では、これは素晴らしい結果です。 また、ヒストグラムの形成とビジネスロジックの検証のために、応答時間中にわずかな（約5〜10ミリ秒）オーバーヘッドが追加されることも非常にクールです。

ただし、このソリューションには欠点もあります。ステータスが200でないリクエストの時間を考慮していません。理由は、log_by_luaディレクティブであり、ロギングを追加しました。この場合は呼び出されません。 こちらが確認です。 一方、これは間違いであるため、このようなリクエストの応答時間には関心がありません。 もう1つのマイナス点は、ヒストグラムがNginx共有メモリに保存されることです。 Nginxを再起動すると、メモリがクリアされ、収集されたメトリックが失われます。 また、これと一緒に生きることができます-reloadコマンドでNginxを再起動し、より頻繁にメトリックを取得するようにPrometheusを構成します。

ヒストグラムを作成するためのNginx設定は次のとおりです。

 lua_shared_dict prometheus_metrics 10M; init_by_lua ' prometheus = require("prometheus").init("prometheus_metrics") prometheusHelper = require("prometheus_helper") metric_request_time = prometheus:histogram("nginx_http_request_time", {"api_method_end_point", "request_method"}) ' 

ここで、共有メモリを選択し、ライブラリとヘルパーをビジネスロジックに接続し、ヒストグラムを初期化します-名前とラベルを割り当てます。

この構成は、要求をログに記録します。

 location / { log_by_lua ' api_method_end_point = prometheusHelper.convert_request_uri_to_api_method_end_point(ngx.var.request_uri, ngx.var.request_method) if (api_method_end_point ~= nil) then metric_request_time:observe(tonumber(ngx.var.request_time),{api_method_end_point, ngx.var.request_method}) ' } 

ここで、log_by_luaディレクティブでリクエストを記録するかどうかをチェックし、記録する場合は、ヒストグラムに応答時間を追加します。

メトリックは、エンドポイントごとにNginxを介して提供されます。

 server { listen 9099; server_name api1.2gis.com; location /metrics { content_by_lua 'prometheus:collect()'; } } 

次に、Prometheus構成でメトリックを収集するためのアプリケーションのノードを指定する必要があります。

  - targets: - api1.2gis.com:9099 - api2.2gis.com:9199 labels: job: bizaccount type: nginx role: monitoring-api-methods team: lk project: backend 

ターゲットセクションにはノードのエンドポイントが表示され、ラベルセクションには収集されたメトリックに追加されるラベルが表示されます。 それらから、メトリックと送信者の目的を決定します。

15秒ごとにメトリックコレクションが構成されています-Prometheusは指定されたノードに移動し、メトリックを保存します。

メトリックを把握し、それらを収集し、Prometheusに渡す方法を学習した後、統合の目的、つまりアプリケーションの速度が低下した場合のコマンドメールのアラートに進みました。 次にアラートの例を示します。

 ALERT BizaccountAPI95PercentileUnreachebleGetUsers IF (sum(rate(nginx_http_request_time_bucket{le="0.4",api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method) / sum(rate(nginx_http_request_time_count{api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method)) * 100 < 95 FOR 5m LABELS { severity = "critical", team = "lk"} ANNOTATIONS { summary = "API-method {{ $labels.request_method}} {{ $labels.api_method_end_point}} is not in SLA", description = "For API-method {{ $labels.request_method}} {{ $labels.api_method_end_point }} 95 percentile is unreacheble in last 5 minutes. Current percentile is {{ $value }}.", } 

Prometheusには簡潔なクエリ生成言語があり、これを使用して期間のメトリック値を選択し、ラベルでフィルタリングできます。 IFディレクティブでは、言語構造を使用して、トリガー条件を指定します-直前の5分間のリクエストの95パーセント未満が0.4秒で応答する場合。 これは態度と見なされます。 分子では、最後の5分間に0.4秒でスタックされるリクエストの数を計算します。

 sum(rate(nginx_http_request_time_bucket{le="0.4",api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method) 

分母では、最後の5分間のリクエストの総数を考慮します。

 sum(rate(nginx_http_request_time_count{api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method) 

結果の小数に100を掛けて、0.4秒で応答するクエリの割合を取得します。 ここのレート関数は、指定された間隔の各瞬間の応答時間を返します。 sum関数は、結果のシリーズを合計します。 by演算子は、指定されたラベルでグループ化を実行するGROUP BY演算子に類似しています。

FORセクションでは、最初のトリガーとアラートを送信する必要がある瞬間の間隔がトリガーされます。 間隔は5分です。5分以内に状況が変わらない場合は、アラートを送信する必要があります。 LABELSセクションには、チームと問題の重大度を示すラベルが表示されます。 ANNOTATIONSセクションは、問題のあるメソッドと、0.4秒で応答するリクエストの割合を示します。

繰り返しアラートが発生した場合、Prometheusは重複排除を行い、1つのアラートをコマンドメールに送信できます。 そして、これはすべてそのままで、ルールとトリガー間隔を指定するだけです。

Prometheusのアラートは、正確な構成であり、アラートの重複排除機能を備えた自転車や、どの言語でもアラートをトリガーするロジックを実装することなく、明確に構成されています。

メッセージは次のようになります。

おわりに

ロギングシステムを改善し、情報不足の問題はなくなりました。

1. エラーが発生した場合、問題に関する十分な情報があります。 現在、テクニカルサポートリクエストの99％について、ユーザーに何が起こったかを把握し、問題と修正の可能性のある条件についてテクニカルサポートを正確に方向付けています。
2. アラートを使用して、アプリケーションのパフォーマンスの問題領域を特定し、それらを最適化して、アプリケーションをより高速で信頼性の高いものにします。
3. Prometheusを使用して、速度の低下をすばやく見つけ、その後ELKを調べて、何が起こったのかを詳細に調査し始めます。 ELK + Prometheusには大きな可能性があります。エラーが増加した場合にアラートを追加し、外部サービスを監視する予定です。