dd-agentや各種インテグレーションの設定のデバッグ方法(分析編)

dd-agentに関連する問題の大半は、configファイルの設定に関するモノになります。従って、ログファイルと設定ファイルを一通り精査することで問題の箇所が見えてくることが多いです。

デバッグの前に確認すること

dd-agentを使った監視を進める上で、欠かせない確認事項が以下になります。

• サーバーの時間のずれていないか?
  dd-agentは、サーバーに設定されている時間を基にUnix時間のタイムスタンプ生成し、メトリクスのそれを付加して、Datadogのバックエンドに送信しています。サーバーの時間が数分遅れていると、今現在受信したメトリクスも、数分前のモノとて表示されて、実際にはリアルタイムでメトリクスが届いているにもかかわらず、グラフ上で届いていないように見えることがあります。更にdd-agent内では、確実にメトリクスが届いていることを確認するために、バックエンドからのhttpのレスポンス時間も計測しています。サーバーの時間がずれていると、メトリクスが届いているにもかかわらず、メトリクスが届いていないと判断されることがあります。このような事態を避けるために、NTP等を使いサーバーの時間を正確に設定しておくのは、Datadogでインフラ監視を進める上での最も重要な作業になります。

• 最新版のdd-agentを使っているか?
  dd-agentは、改善され続けています。新しいミドルウェアに対応するために更新することも有りますが、その横で多くのbug fixが実施されています。dd-agentのOSS公開以降のchange logを見ていると新規に追加されたintegration以外は、最新版が最も枯れていると言ってよいような状況になっています。従って、特段の理由のない限り、最新のdd-agentに更新した上でデバッグを進めるのは、不必要なデバッグを発生させないようにするためにも賢い選択です。

dd-agentのchangelogの詳細は、githubで確認することができます。

デバッグに必要なファイルを収集する方法

dd-agentの設定ファイルと各logファイルを評価していけば、問題の原因を見極めることは難しくありません。しかしながら、それらのファイルは、OS上の色々な場所に分散して保存されているので、下記のコマンドを使って一カ所に集めてくると便利です。

Linux系OSの場合は、以下のコマンドを実行します。

# /etc/init.d/datadog-agent flare

このコマンドは、Datadogのサポート時にlogファイルと設定ファイルの送信手順を簡素化するために作られました。
従って、ディバッグに必要な全てのlogファイルと設定ファイルをワンコマンドで収集してくれた上で、出来上がったアーカイブをDatadogへ送信するべきかの旨を聞いてきます。

今回は、Datadogのサポートへディバッグに必要なアーカイブを送信する予定がないので n と回答します。

2016-12-01 14:19:52,782 | INFO | dd.collector | utils.flare(flare.py:135) | Saving all files to /tmp/datadog-agent-2016-12-01-14-19-51.tar.bz2
/tmp/datadog-agent-2016-12-01-14-19-51.tar.bz2 is going to be uploaded to Datadog.
Do you want to continue [Y/n]?

/tmp以下のディレクトリに datadog-agent-2016-12-01-14-19-51.tar.bz2 という、アーカイブファイルができます。(ファイル名の日付と時間は、flareコマンドの時効時間になります)

このアーカイブを展開してみると、次の様なファイルが現れます。

root@ubuntu-xenial:/tmp# tar jxf datadog-agent-2016-12-01-14-19-51.tar.bz2
root@ubuntu-xenial:/tmp# cd datadog-ubuntu-xenial.localdomain/
root@ubuntu-xenial:/tmp/datadog-ubuntu-xenial.localdomain# tree
.
├── configcheck.log
├── etc
│   ├── confd
│   │   ├── agent_metrics.yaml.default
│   │   ├── disk.yaml.default
│   │   ├── network.yaml.default
│   │   └── ntp.yaml.default
│   ├── datadog.conf
│   └── supervisor.conf
├── freeze.log
├── info.log
├── log
│   ├── collector.log
│   ├── dogstatsd.log
│   ├── forwarder.log
│   ├── jmxfetch.log
│   └── supervisord.log
├── permissions.log
├── sd_configcheck.log
└── status.log

3 directories, 17 files

etc/dd-agent/conf.d内の設定ファイルはetc以下へ、logファイルはlog以下へコピーされます。ディレクトリの直下のconfigcheck.log, freeze.log, info.log, permissions.log, sd_configcheck.log, status.logは、/etc/init.d/datadog-agent {info|status|configcheck|}のオプションに相当し、flareの実行の度に自動で生成されます。

logの見方

まず注目すべきは、info.logです。このlogには、まず最初に把握したい重要な情報が記録されています。

• System UTC timeとDatadogバックエンドとの時間のずれ

 Clocks
  ======

    NTP offset: -13.6967 s
    System UTC time: 2016-12-05 10:28:06.786909

System UTC timeよりサーバ内に設定されているUTC時間を把握し、offsetよりその時間が、datadogのバックエンドとどれくらいずれているのかを把握します。(Datadogのバックエンドは、NTPにより常に正確に時間調整されています。)

• agent version

Collector (v 5.10.1)

Dogstatsd (v 5.10.1)

Forwarder (v 5.10.1)

v 5.10.1より、dd-agentの5.10.1が動作していることが分かります。

• 動作しているcheckの種類と動作状況

Checks
  ======

    ntp
    ---
      - Collected 0 metrics, 0 events & 0 service checks

    disk
    ----
      - instance #0 [OK]
      - Collected 32 metrics, 0 events & 0 service checks

    network
    -------
      - instance #0 [OK]
      - Collected 15 metrics, 0 events & 0 service checks

インストールされているチェックにエラーがある場合、エラーの状況が表示されます。又、収集しているメトリクス、イベント、チェックの数がそれぞれ表示される為、目的の情報が集取できているかを大枠で把握する事ができます。

info.logで大方の状況を把握した後に、collector.log, forwarder.log, dogstatsd.log, permissions.log, configcheck.logを見ていきます。一般的には、これらのlogファイルを精査すると、原因となっている箇所が見えてきます。

今回筆者の時間の都合上、コードを掲載してエラーの詳細を見せることはできませんが、サポートに頻繁に上がってくるエラーを解説しておきます。

遭遇しやすいエラー

• 設定yamlファイルのsyntaxは間違っていないか?
  dd-agentのintegrationを初めて設定する場合、一番多く見かけるエラーがyamlのsyntaxエラーです。-やスペースの数などの不注意で、ファイルが読み取れないことが多々あります。従って、on-line上のyamlチェッカーなどで、yamlシンタックスを予め確認しておけば、有効にデバッグを進めることができるでしょう。yamlのエラーは、info.logのcheckのセクションやconfigcheck.logに明らかに分かるように表示されているので、簡単に見つけられると思います。

• ゾンビ化しているdd-agentプロセスが存在していないか?
  "dd-agentが正しく起動しない"、"supervisord.logを精査しているとdd-agentが頻繁にターミネートされている"などの症状がある場合は、(1)ps aux | grep datadogなど存在しているプロセスが確認できるCLIコマンドを実行し、dd-agentに関連するプロセスを全てkillした後、dd-agentを起動すことで症状が解消されるはずです。それでも症状が解消されない場合は、そのサーバーを再起動すると症状が改善したケースも多くあります。個人的には、ゾンビ化したdd-agentプロセスが有るかもと思ったら迷わず、インスタンスを再起動するのが最も簡単だと思っています。

• 599 timeout
  最もやっかいな症状です、forwarder.logを精査していると長いエラーメッセージの中に599 timeoutと書かれていることがあります。サーバーの時間が正しく設定できている場合、datadogのバックエンドまでの経路間のMTUの問題がパケットがブラックホールに吸い込まれている状況になります。このパターンのエラーを見たら、最初にすることは、Datadogのバックエンドと通信しているネットワークインターフェースのMTU調整になります。英語になりますが、詳しくは、HTTPError('HTTP 599: Timeout',) appearing in logsのナレッジベースを見ると詳しく知ることができます。

• firewallでdd-agentが使っている通信ポートを閉じていないか?
  既に紹介した三つほどでは有りませんが、firewallの設定でdatadogのバックエンドに対して通信できていないケースの見かけます。この症状は、fowarder.logを精査しているとエラーが出ているのが分かります。そんなときは、サーバー内のfirewallの設定やサーバーとdatadogのバックエンドの間に設定してあるfirewallの設定を確認してみてください。dataodg.confで細かく変更していない限り、基礎知識編で紹介したポートは全て通信ができるようになっている必要があります。

これ以外にも一般的な事例は、Datadogのサポート用ナリッジベースに載っています。上記で紹介できなかったケースに関しては、こちらを参照してください。

更に詳しくlogを取る方法

dd-agentには、詳しくログを収集する機能があります。一般的なレベルのログで問題の原因が見つけられない場合は、開発者かディバッグに使うレベルまで引き上げて記録することができます。

datadog.confの下記の行の#を外し、次のように編集します。

https://github.com/DataDog/dd-agent/blob/master/datadog.conf.example#L52

developer_mode: yes

https://github.com/DataDog/dd-agent/blob/master/datadog.conf.example#L240

log_level: DEBUG

編集が終了したところでdd-agentを再起動し、十分にログを集取した後、再度/etc/init.d/datadog-agent flareを実行し、アーカイブを作成します。

技術サポートの依頼

上記の方法でデバッグしも未だ原因が分からない場合は、flareコマンドで収集したアーカイブを添付して[e-mail]にメールで問い合わせます。

その際、ログインに使っているメールアドレスと、dd-agentをインストールしようとしているサーバを登録している、又は登録したいOrg名を付記して問い合わせると、状況調査のためのOrg_idを識別しやすいので、サポートがスムーズに始められます。

尚、サポートへの問い合わせは日本語でもOKです。英語のあまり自信のない人も安心して日本語で問い合わせてください。(驚くことに、多くの日本のユーザは、英語で問い合わせをしています。日本のエンジニアもまんざら世界に通用するのでは思えてきます。)

まとめ

dd-agentが出すエラーのデバッグは、精査する情報のありかが分かれば非常に簡単な作業です。又、dd-agentのソースコードはgithubで公開されているため、出ているエラーメッセージを検索すると、そのエラーを出力している直前のコードで何をしているかを見ることもできます。

次回からdd-agentに何かの問題が発生しても慌てることはありません。上記の方法でアーカイブを作って、紹介したファイルを精査してみてください。Qiitaを読んでるエンジニアなら、エラーの原因となっている設定ファイルの修正箇所を、見つけ出すことできると思います。

NYC, New York timesビル Datadog HQからの投稿になります。時間がなく乱筆になり申し訳ありません。