はじめに
この記事は、Microsoft Azure Tech Advent Calendar 2019 の 17 日目の記事です。
各種 Azure サービスについては他の方が投稿してくださっておりますので、今回はどちらかというと裏方の役割を担う機能についてご紹介します。
概要
本日のエントリーは、使ってみると割と便利な Kusto についてです。サービスの運用を行う際には、有事に備えてログを出力するのは必要不可欠ですが、サーバーのローカル領域やストレージにログを出力することが一般的かと思います。そして、サービスが正常稼働している間はログを細かく確認する必要がないため、大きな問題が発生することはないかと思います。しかし、サービスに問題が発生して実際にログを確認する必要が出てきた場合には、1 秒でも早く問題を解決したい状況下で、膨大なログの中から事象発生時の数行/数十行のログを見つけるのは非常に時間のかかる大変な作業です。Kusto は、KQL (Kusto Query Language) と呼ばれる検索言語を使い、Azure Log Analytics に格納したログを効率的に検索するための機能で、上記のような悩みを解決できます。
最大の特徴は、膨大なログを高速に検索できること、そして Azure の多くのサービス、さらには Azure 外で稼働するサービスのログを横断的に検索できることです。しかし、KQL という独自の検索言語を利用するため、なんだかよくわからないので使ったことがないという方も多いと思います。本日は、Kusto を少しでも身近に感じていただくために、よく使うクエリーをご紹介させていただきます。
事前準備
Kusto を利用する上で、以下の事前準備が必要となります。
- Log Analytics のデプロイ
- 各サービスで Log Analytics にログを送信するよう設定
1. Log Analytics のデプロイ
Azure ポータルの左上にある [+ リソースの作成] から Log Analytics と検索してデプロイします。
なお、Application Insights は Log Analytics が内包されているため、明示的に Log Analytics をデプロイする必要はありませんが、基本的には Log Analytics のデプロイが必要です。
2. 各サービスで Log Analytics にログを送信するよう設定
各サービスの監視、OS の監視、アプリケーションの監視でそれぞれ設定方法が異なります。
各サービスの監視
多くの Azure サービスは、Azure ポータル上の操作でログを Log Analytics に送信するように設定することができます。Azure ポータルからは様々な設定が可能ですが、[監視] という項目は多くのサービスで共通しており、その中の [診断設定] から診断設定の定義を追加し、送付したいログを指定することで、ログを Log Analytics に送信することができます。また、同様の方法で、Log Analytics の他に Azure Storage や Event Hub にもログを送信することができます。詳細はこちらのドキュメントにも記載がございます。
OS の監視
OS ログは、Windows/Linux によらず Log Analytics エージェントをインストールすることで取得が可能です。Log Analytics エージェントのインストーラーは、Azure ポータルで Log Analytics を開き、[詳細設定] - [Connected Sources] からダウンロードできます。インストール時にはワークスペース ID と主キーが必要ですので、インストーラーのダウンロード時にコピーをしておきます。
そして、エージェントのインストールが完了した後、同じ画面の [Data] から Log Analytics に送信するログを指定します。
なお、Log Analytics エージェントはオンプレミスのサーバーにもインストールできますので、Azure VM 以外のサーバーのログも Kusto で検索できます。こちらの資料も、ご参考になりますと幸いです。
アプリケーションの監視
アプリケーションのログは、Application Insights をご利用いただくことで Kusto を利用した検索が可能となります。Application Insights は、アプリケーションに Application Insights SDK を含めることですぐに利用ができ、アクセス数などのテレメトリ情報が確認できるようになります。さらに、SDK を利用することで独自のログも Application Insights に送信することができ、Kusto で検索できるようになります。Application Insights は、.NET、Java、Node.js、Python など、複数の言語で利用でき、かつクラウド、オンプレミスによらず利用可能です。
よく使うクエリーの紹介
実際に利用する前に、よく使うクエリーをご紹介していきます。
KQL のクエリーの概要についてはこちらのドキュメントがありますが、正直すべてを覚えるのは大変です。一方で、where、summarize、project、render という 4 つの句で基本的なログ検索は可能ですので、本日はよく使うこれらの句についてご紹介します。これさえ覚えれば、すぐに Kusto が使えます！
where 句
KQL で最も利用する句で、検索時の条件を指定する際に利用します。
各種ログは、テーブル形式で Log Analytics に保存されます。そのため、where 句を利用して検索したいログの条件を指定します。例えば、1 時間前までのログのみを確認したい場合、時間間隔を指定してログを見たい場合はそれぞれ以下のように記載します。
# 1 時間前までのログを確認
where TimeGenerated >= ago(1h)
# 期間を指定してログを確認 (UTC 時間)
where TimeGenerated >= todatetime('2019-12-10T00:00:00') and TimeGenerated <= todatetime('2019-12-17T00:00:00')
summarize 句
ログの数や平均値の算出など、ログの内容を集計する際に利用します。
例えば、IIS のログを見る上で各 HTTP ステータス コードの数を比較したい場合や、HTTP リクエストに要した平均時間 (いわゆる Time Taken の平均値) を確認したい場合がありますが、それぞれ以下の通り記載します。
# HTTP ステータス コードごとの数を確認
summarize count() by scStatus
# HTTP リクエストに要した時間
summarize avg(TimeTaken)
project 句
検索結果を出力する際に、出力するスキーマを絞りたい場合に利用します。
上記の通り、各種ログはテーブル形式で保存されておりますが、すべての情報を見る必要がない場合もあります。その場合には project 句を利用し、出力されるスキーマを絞ります。例えば、IIS ログの中で、時間、HTTP メソッド、宛先パス、宛先ポート、ユーザー エージェント、HTTP ステータス コードのみを見たい場合は以下のように記載します。(スキーマの書き順通りに結果が出力されます)
project TimeGenerated , csMethod , sPort , csUserAgent , scStatus
render 句
ログの検索結果をチャートやグラフに可視化する際に利用します。ログを検索する上で必須ではありませんが、見栄えがよくなりますのでレポートの作成などに利用できます。
render 句では、折れ線グラフや棒グラフ、円グラフなどが利用でき、render 句のあとに利用したいグラフの形式を記載するだけで可視化できます。
# 横軸を時間とした棒グラフ
render timechart
# 棒グラフ
render barchart
# 円グラフ
render piechart
実際にログを確認してみる
それでは、ご紹介した 4 つの句を利用して実際のログを確認していきます。今回は、Azure Windows VM に構築した Web サーバー上で動作するアプリケーションでいきなりエラーが発生するようになったため、IIS ログを確認する必要がある状況とします。ログの検索は、Azure ポータルで Log Analytics (アプリケーションの場合は Application Insights) を表示し、[ログ] というブレードから実施します。
0. はじめの一歩 (慣れてきたら省略可)
とにもかくにも、ログのテーブル名やスキーマ名がわからないと条件を指定しての検索は難しいと思います。そのため、まずは条件を何も指定せずに全部のログを表示して、テーブル内にどのような情報が含まれているかを見てみるのがいいと思います。慣れてくればこの作業は飛ばしてしまって大丈夫です。
例えば、IIS ログを確認したい場合、IIS のログ テーブルを探すためにとりあえず IIS と検索してみます。
すると、それっぽい W3CIISLog というテーブルが見つかったので、それをそのままダブル クリックしてみます。ダブル クリックをすると右側の検索ウィンドウに W3CIISLog というクエリーが記載されるので、[▷ 実行] ボタンを押してみます。
なにやらたくさんログが出て、時間は TimeGenerated、HTTP メソッドは csMethod、宛先パスは csUriStem、ユーザー エージェントは csUserAgent というようにテーブルに含まれるスキーマ名が確認でき、それぞれのデータ型も左ペインを展開することで確認できます。今回は IIS ログを例としましたが、Windows のイベント ログは "Event"、Linux の Syslog は "Syslog" など、見たいログのキーワードで検索をすれば、だいたいのログは確認できるかと思います。私も初めて見るログは、この方法で見たい情報を絞り込むようにしています。
1. 特定の期間のログを見てみる
それでは、実際にログを絞り込んでいきます。まずは時間の絞り込みからです。ログを見る場合、基本的には何らかの問題が発生した時間前後のログを見るかと思いますが、テキスト エディターなどでログを確認する場合、この作業だけで多くの労力を費やします。Kusto を利用することで、1 行で時間帯を絞り込むことが可能です。
W3CIISLog
| where TimeGenerated >= todatetime('2019-12-17T00:00:00') and TimeGenerated <= todatetime('2019-12-17T01:00:00')
IIS ログは、時間情報が TimeGenerated というスキーマに格納されるので上記のクエリーになりますが、時間情報が含まれるスキーマの名称は適宜ご変更ください。
2. エラーが発生している URL を見てみる
時間は絞り込めたので、続いてどのようなエラーが発生しているかを見てみます。Web アプリケーションの場合、HTTP ステータス コードでエラー内容が確認できますので、どのようなエラーがどのくらい発生しているかを絞ってみます。HTTP ステータス コードは、HTTP 400 以上が何らかのエラーを意味するのでまずはざっくりと HTTP 400 以上のログを見てみます。(W3CIISLog テーブルでは、ステータス コードの情報が String 型で格納されているので int 型に変換します。また、多数の情報が表示されるため、project 句で表示されるデータを絞っています。)
W3CIISLog
| where TimeGenerated >= todatetime('2019-12-17T00:00:00') and TimeGenerated <= todatetime('2019-12-17T01:00:00')
| where toint(scStatus) >= 400
| project TimeGenerated , Date , Time , csMethod , csUriStem , scStatus
HTTP 500 エラーのログが多数記録されているようですが、どのパスでエラーが発生しているか、もう少し絞り込んでみます。
W3CIISLog
| where TimeGenerated >= todatetime('2019-12-17T00:00:00') and TimeGenerated <= todatetime('2019-12-17T01:00:00')
| where toint(scStatus) >= 400
| summarize count() by csUriStem
3. 他の URL でエラーが発生しているかも確認しておく
ここまでで、"/api/createtodoitem" というパスで HTTP 500 エラーが発生していたということがわかりましたが、念のため他のパスでエラーが発生していないかも確認しておきます。
W3CIISLog
| where TimeGenerated >= todatetime('2019-12-17T00:00:00') and TimeGenerated <= todatetime('2019-12-17T01:00:00')
| summarize count() by csUriStem , scStatus
どうやら "/api/createtodoitem" 以外のパスは正常に稼働していそうですね。つまり、CreateTodoItem API を調査すれば問題は解決すると考えられます。ちなみに、Application Insights を利用することで特別な設定なしにエラー発生時のコール スタックなどが確認でき、この後の調査もスムーズに実施できると思いますのでおすすめです。
おまけ
render 句を使って 1 分ごとの HTTP ステータス コードの数をグラフ化してみます。1 分ごとといった指定は bin() 関数を利用して指定ができます。必ずしも render 句を利用する必要はありませんが、レポートの作成時などに重宝できる機能かと思います。
W3CIISLog
| where TimeGenerated >= todatetime('2019-12-17T00:00:00') and TimeGenerated <= todatetime('2019-12-17T01:00:00')
| summarize count() by bin(TimeGenerated, 1m) , scStatus
| render timechart
まとめ
簡単ではありますが、本日は使ってみると意外と便利な Kusto についてご紹介しました。運用環境の膨大なログを確認する場合、ログの検索性は非常に重要かと思います。今までは、テキスト エディターなどでログ ファイルを開き、目をしょぼしょぼさせながら血眼で該当箇所のログを探してた日々もあったかと思います。Kusto を利用することで、時間や確認したいログの絞り込みだけではなく、集計や可視化が一瞬でできるので、ぜひ一度使ってみてください！