第14章 ロギングと監視

OpenStackクラウドは、様々なサービスから構成されるため、多くのログファイルが存在します。このセクションでは、それぞれのログの場所と取り扱い、そしてシステムのさらなる監視方法について説明します。

 ログはどこにあるのか?

Ubuntu では、ほとんどのサービスが /var/log ディレクトリ以下のディレクトリにログファイルを出力するという慣習に従っています。

 クラウドコントローラー

サービス ログの場所

nova-*

/var/log/nova

glance-*

/var/log/glance

cinder-*

/var/log/cinder

keystone

/var/log/keystone

horizon

/var/log/apache2/

その他 (Swift, dnsmasq)

/var/log/syslog

 コンピュートノード

libvirt: /var/log/libvirt/libvirtd.log

VMインスタンスのコンソール (ブートメッセージ): /var/lib/nova/instances/instance-<instance id>/console.log

 ブロックストレージ ノード

cinder: /var/log/cinder/cinder-volume.log

 ログの読み方

OpenStack サービスは標準のロギングレベルを利用しています。重要度のレベルは次の通りです(重要度の低い順): DEBUG、INFO、AUDIT、WARNING、ERROR、CRTICAL、TRACE。特定のログレベルより「重要」な場合のみメッセージはログに出力されます。ログレベルDEBUGの場合、すべてのログが出力されます。TRACEの場合、ソフトウェアがスタックトレースを持つ場合にのみログに出力されます。INFOの場合、情報のみのメッセージも含めて出力されます。

DEBUG レベルのロギングを無効にするには、以下のように /etc/nova/nova.conf を編集します。

debug=false

Keystoneは少し異なる動作をします。ロギングレベルを変更するためには、/etc/keystone/logging.confを編集し、 logger_roothandler_file を修正する必要があります。

Horizon のロギング設定は /etc/openstack_dashboard/local_settings.py で行います。Horizon は Django web アプリケーションですので、Django Logging (https://docs.djangoproject.com/en/dev/topics/logging/) フレームワークの規約に従います。

エラーの原因を見つけるための典型的な最初のステップは、 CRTICAL、TRACE、ERRORなどのメッセージがログファイルの終わりで出力されていないかを確認することです。

トレース(Pythonのコールスタック)付きのCRITICALなログメッセージの例は次の通りです。

2013-02-25 21:05:51 17409 CRITICAL cinder [-] Bad or unexpected response from the storage volume backend API: volume group 
 cinder-volumes doesn't exist
2013-02-25 21:05:51 17409 TRACE cinder Traceback (most recent call last):
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/bin/cinder-volume", line 48, in <module>
2013-02-25 21:05:51 17409 TRACE cinder service.wait()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/service.py", line 422, in wait
2013-02-25 21:05:51 17409 TRACE cinder _launcher.wait()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/service.py", line 127, in wait
2013-02-25 21:05:51 17409 TRACE cinder service.wait()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 166, in wait
2013-02-25 21:05:51 17409 TRACE cinder return self._exit_event.wait()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/eventlet/event.py", line 116, in wait
2013-02-25 21:05:51 17409 TRACE cinder return hubs.get_hub().switch()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 177, in switch
2013-02-25 21:05:51 17409 TRACE cinder return self.greenlet.switch()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 192, in main
2013-02-25 21:05:51 17409 TRACE cinder result = function(*args, **kwargs)
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/service.py", line 88, in run_server
2013-02-25 21:05:51 17409 TRACE cinder server.start()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/service.py", line 159, in start
2013-02-25 21:05:51 17409 TRACE cinder self.manager.init_host()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 95, 
 in init_host
2013-02-25 21:05:51 17409 TRACE cinder self.driver.check_for_setup_error()
2013-02-25 21:05:51 17409 TRACE cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/driver.py", line 116, 
 in check_for_setup_error
2013-02-25 21:05:51 17409 TRACE cinder raise exception.VolumeBackendAPIException(data=exception_message)
2013-02-25 21:05:51 17409 TRACE cinder VolumeBackendAPIException: Bad or unexpected response from the storage volume 
 backend API: volume group cinder-volumes doesn't exist
2013-02-25 21:05:51 17409 TRACE cinder

この例では、ボリュームのバックエンドがストレージボリュームをセットアップができなかったため、cinder-volumesが起動に失敗し、スタックトレースを出力しています。おそらく、設定ファイルで指定された LVM ボリュームが存在しないためと考えられます。

エラーログの例:

2013-02-25 20:26:33 6619 ERROR nova.openstack.common.rpc.common [-] AMQP server on localhost:5672 is unreachable:
 [Errno 111] ECONNREFUSED. Trying again in 23 seconds.

このエラーでは、novaサービスがRabbitMQへの接続に失敗していました。接続が拒否されたというエラーが出力されています。

 インスタンスリクエストの追跡

インスタンスが正しく動作していない場合、インスタンスに関連したログを調べる必要があります。これらのログは複数のnova-*サービスが出力しており、クラウドコントローラーとコンピュートノードの両方に存在します。

一般的な方法はインスタンスのUUIDをキーにして、各サービスのログを追跡することです。

次のような例を考えてみましょう。

ubuntu@initial:~$ nova list
+--------------------------------------+--------+--------+---------------------------+
| ID                                   | Name   | Status | Networks                  |
+--------------------------------------+--------+--------+---------------------------+
| faf7ded8-4a46-413b-b113-f19590746ffe | cirros | ACTIVE | novanetwork=192.168.100.3 |
+--------------------------------------+--------+--------+---------------------------+

ここで、インスタンスのUUIDは faf7ded8-4a46-413b-b113-f19590746ffeです。クラウドコントローラー上の /var/log/nova-*.logファイルをこの文字列で検索すると、nova-api.lognova-scheduler.logで見つかります。同様にコンピュートノードで検索した場合、nova-network.lognova-compute.logで見つかります。もし、ERRORやCRITICALのメッセージが存在しない場合、最後のログエントリが、何が悪いかのヒントを示しているかもしれません。

 カスタムログの追加

もし、ログに十分な情報がない場合、あなた自身でカスタマイズしたログを nova-*サービスに追加することができます。

ソースファイルは /usr/lib/python2.7/dist-packages/novaに存在します。

ログステートメントを追加するには、次の行をファイルの先頭に置きます。ほとんどのファイルでは、これらは既に存在します。

from nova.openstack.common import log as logging
LOG = logging.getLogger(__name__)

DEBUGログステートメントを追加するには次のようにします。

LOG.debug("This is a custom debugging statement")

以下に例を示しますが、全てのログメッセージはアンダースコアで始まり、括弧で括られていることに気づいたでしょうか?

LOG.debug(_("Logging statement appears here"))

これは、ログメッセージを異なる言語に翻訳するためにgettext (http://docs.python.org/2/library/gettext.html) 国際化ライブラリ を利用しているためです。カスタムログには必要ありませんが、もし、OpenStackプロジェクトにログステートメントを含むコードを提供する場合は、アンダースコアと括弧でログメッセージを囲わなければなりません。

 RabbitMQ Web管理インターフェイス および rabbitmqctl

接続失敗の問題は別とすると、RabbitMQログファイルはOpenStackに関連した問題のデバッグにあまり有用ではありません。その代わりにRabbitMQ Web管理インターフェイスを推奨します。 クラウドコントローラーにおいて、以下のコマンドで有効になります。

# /usr/lib/rabbitmq/bin/rabbitmq-plugins enable rabbitmq_management
# service rabbitmq-server restart

RabbitMQ Web管理インターフェイスは、クラウドコントローラーから http://localhost:55672 でアクセスできます。

[注記]注記

Ubuntu 12.04はRabiitMQのバージョン2.7.1を55672番ポートを使うようにインストールします。RabbitMQバージョン3.0以降では15672が利用されます。Ubuntuマシン上でどのバージョンのRabbitMQが実行されているかは次のように確認できます。

$ dpkg -s rabbitmq-server | grep "Version:"
Version: 2.7.1-0ubuntu4

RabbitMQ Web 管理インターフェイスを有効にするもう一つの方法としては、 rabbitmqctl コマンドを利用します。例えば rabbitmqctl list_queues| grep cinder は、キューに残っているメッセージを表示します。メッセージが存在する場合、CinderサービスがRabbitMQに正しく接続できてない可能性があり、再起動が必要かもしれません。

RabbitMQで監視すべき項目としては、各キューでのアイテムの数と、サーバーでの処理時間の統計情報があります。

 ログの集中管理

クラウドは多くのサーバーから構成されるため、各サーバー上にあるイベントログを繋ぎあわせて、ログをチェックしなければなりません。よい方法は全てのサーバーのログを一ヶ所にまとめ、同じ場所で確認できるようにすることです。

Ubuntuはrsyslog をデフォルトのロギングサービスとして利用します。rsyslog はリモートにログを送信する機能を持っているので、何かを追加でインストールする必要はなく、設定ファイルを変更するだけです。リモート転送を実施する際は、盗聴を防ぐためにログが自身の管理ネットワーク上を通る、もしくは暗号化VPNを利用することを考慮する必要があります。

 rsyslog クライアント設定

まず始めに、全てのOpenStackコンポーネントのログを標準ログに加えてsyslogに出力するように設定します。また、各コンポーネントが異なるsyslogファシリティになるように設定します。これによりログサーバー上で、個々のコンポーネントのログを分離しやすくなります。

nova.conf:

use_syslog=True
syslog_log_facility=LOG_LOCAL0

glance-api.conf および glance-registry.conf:

use_syslog=True
syslog_log_facility=LOG_LOCAL1

cinder.conf:

use_syslog=True
syslog_log_facility=LOG_LOCAL2

keystone.conf:

use_syslog=True
syslog_log_facility=LOG_LOCAL3

Swift

デフォルトでSwiftはsyslogにログを出力します。

次に、 /etc/rsyslog.d/client.confに次の行を作成します。

*.* @192.168.1.10

これは、rsyslogに全てのログを指定したIPアドレスに送るように命令しています。この例では、IPアドレスはクラウドコントローラーを指しています。

 rsyslog サーバー設定

集中ログサーバーとして使用するサーバーを決めます。ログ専用のサーバーを利用するのが最も良いです。 /etc/rsyslog.d/server.conf を次のように作成します。

# Enable UDP 
$ModLoad imudp 
# Listen on 192.168.1.10 only 
$UDPServerAddress 192.168.1.10
# Port 514 
$UDPServerRun 514  
      
# Create logging templates for nova
$template NovaFile,"/var/log/rsyslog/%HOSTNAME%/nova.log" 
$template NovaAll,"/var/log/rsyslog/nova.log"
      

      
# Log everything else to syslog.log 
$template DynFile,"/var/log/rsyslog/%HOSTNAME%/syslog.log"
*.* ?DynFile
      

      
# Log various openstack components to their own individual file
local0.* ?NovaFile 
local0.* ?NovaAll 
& ~

この設定例はnovaサービスのみを扱っています。はじめに rsyslog を UDP 514番ポートで動作するサーバーとして設定します。次に一連のログテンプレートを作成します。ログテンプレートは受け取ったログをどこに保管するかを指定します。上記の例を用いると、c01.example.comから送られるnovaのログは次の場所に保管されます。

  • /var/log/rsyslog/c01.example.com/nova.log

  • /var/log/rsyslog/nova.log

c02.example.comから送られたログはこちらに保管されます。

  • /var/log/rsyslog/c02.example.com/nova.log

  • /var/log/rsyslog/nova.log

全てのノードからのnovaのログを含む集約されたログだけでなく、個々のコンピュートノードのログも持つことになります。

 StackTach

StackTachはRackspaceによって作られたツールで、novaから送られた通知を収集してレポートします。通知は本質的にはログと同じですが、より詳細な情報を持ちます。通知の概要のよい資料は、System Usage Data(https://wiki.openstack.org/wiki/SystemUsageData)にあります。

novaで通知の送信を有効化するには次の行を nova.confに追加します。

notification_topics=monitor 
notification_driver=nova.openstack.common.notifier.rabbit_notifier

novaが通知を送信するように設定後、StackTachをインストールします。StackTachは新しく、頻繁に更新されるので、インストール手順はすぐに古くなります。StackTach GitHub repo (https://github.com/rackerlabs/stacktach) とデモビデオを参照して下さい。

 監視

二つの監視のタイプがあります。問題の監視と、利用傾向の監視です。前者は全てのサービスが動作していることを保証するものであり、後者は時間に沿ったリソース利用状況を監視することで、潜在的なボトルネックの発見とアップグレードのための情報を得るものです。

 プロセス監視

基本的なアラート監視は、単純に必要なプロセスが実行されているかどうかをチェックすることです。例えば、 nova-apiサービスがクラウドコントローラーで動作していることを確認します。

[ root@cloud ~ ] # ps aux | grep nova-api
nova 12786 0.0 0.0 37952 1312 ? Ss Feb11 0:00 su -s /bin/sh -c exec nova-api --config-file=/etc/nova/nova.conf nova
nova 12787 0.0 0.1 135764 57400 ? S Feb11 0:01 /usr/bin/python /usr/bin/nova-api --config-file=/etc/nova/nova.conf
nova 12792 0.0 0.0 96052 22856 ? S Feb11 0:01 /usr/bin/python /usr/bin/nova-api --config-file=/etc/nova/nova.conf
nova 12793 0.0 0.3 290688 115516 ? S Feb11 1:23 /usr/bin/python /usr/bin/nova-api --config-file=/etc/nova/nova.conf
nova 12794 0.0 0.2 248636 77068 ? S Feb11 0:04 /usr/bin/python /usr/bin/nova-api --config-file=/etc/nova/nova.conf
root 24121 0.0 0.0 11688 912 pts/5 S+ 13:07 0:00 grep nova-api

NagiosとNRPEを使って、クリティカルなプロセスの自動化されたアラートを作成することが可能です。nova-compute プロセスがコンピュートノードで動作していることを保証するために、Nagiosサーバー上で次のようなアラートを作成します。

define service { 
    host_name c01.example.com 
    check_command check_nrpe_1arg!check_nova-compute 
    use generic-service 
    notification_period 24x7 
    contact_groups sysadmins 
    service_description nova-compute 
}

そして、対象のコンピュートノードにおいて、次のようなNRPE設定を作成します。

command[check_nova-compute]=/usr/lib/nagios/plugins/check_procs -c 1: -a nova-compute

Nagiosは常に一つ以上の nova-computeサービスが動作しているかをチェックします。

 リソースのアラート

リソースのアラートは、一つ以上のリソースが極めて少なくなった場合に通知するものです。監視の閾値はインストールされたOpenStackの環境に合わせて設定すべきですが、リソース監視の利用方法は、OpenStackに固有の話ではありません。一般的なアラートのタイプが利用できます。

監視項目に含む幾つかのリソースをあげます。

  • ディスク使用量

  • サーバー負荷

  • メモリ使用量

  • ネットワーク I/O

  • 利用可能な vCPU 数

例として、コンピュートノード上のディスク容量をNagiosを使って監視する場合、次のようなNagios設定を追加します。

define service { 
    host_name c01.example.com 
    check_command check_nrpe!check_all_disks!20% 10% 
    use generic-service 
    contact_groups sysadmins 
    service_description Disk 
}

コンピュートノード上では、次のようなNRPE設定を追加します。

command[check_all_disks]=/usr/lib/nagios/plugins/check_disk -w $ARG1$ -c $ARG2$ -e

Naigosは、80%のディスク使用率でWARNING、90%でCRITICALを警告します。%i_dummy%f_dummy

 OpenStack固有のリソース

メモリ、ディスク、CPUのような一般的なリソースは、全てのサーバー(OpenStackに関連しないサーバーにも)に存在するため、サーバーの状態監視において重要です。OpenStackの場合、インスタンスを起動するために必要なリソースが確実に存在するかの確認という点でも重要です。OpenStackのリソースを見るためには幾つかの方法が存在します。

最初は nova コマンドを利用した例です。

# nova usage-list

このコマンドはテナント上で実行されるインスタンスのリストと、インスタンス全体の簡単な利用統計を表示します。クラウドの簡単な概要を得るのに便利なコマンドですが、より詳細な情報については表示しません。

次に nova データベースは 利用情報に関して3つのテーブルを持っています。

nova.quotasnova.quota_usages テーブルはクォータの情報が保管されています。もし、テナントのクォータがデフォルト設定と異なる場合、nova.quotasに保管されます。以下に例を示します。

mysql> select project_id, resource, hard_limit from quotas; 
+----------------------------------+-----------------------------+------------+
| project_id                       | resource                    | hard_limit |
+----------------------------------+-----------------------------+------------+
| 628df59f091142399e0689a2696f5baa | metadata_items              | 128        |
| 628df59f091142399e0689a2696f5baa | injected_file_content_bytes | 10240      |
| 628df59f091142399e0689a2696f5baa | injected_files              | 5          |
| 628df59f091142399e0689a2696f5baa | gigabytes                   | 1000       |
| 628df59f091142399e0689a2696f5baa | ram                         | 51200      |
| 628df59f091142399e0689a2696f5baa | floating_ips                | 10         |
| 628df59f091142399e0689a2696f5baa | instances                   | 10         |
| 628df59f091142399e0689a2696f5baa | volumes                     | 10         |
| 628df59f091142399e0689a2696f5baa | cores                       | 20         |
+----------------------------------+-----------------------------+------------+ 

nova.quota_usagesテーブルはどのくらいリソースをテナントが利用しているかを記録しています。

mysql> select project_id, resource, in_use from quota_usages where project_id like '628%';
+----------------------------------+--------------+--------+ 
| project_id                       | resource     | in_use | 
+----------------------------------+--------------+--------+ 
| 628df59f091142399e0689a2696f5baa | instances    | 1      |
| 628df59f091142399e0689a2696f5baa | ram          | 512    | 
| 628df59f091142399e0689a2696f5baa | cores        | 1      | 
| 628df59f091142399e0689a2696f5baa | floating_ips | 1      | 
| 628df59f091142399e0689a2696f5baa | volumes      | 2      | 
| 628df59f091142399e0689a2696f5baa | gigabytes    | 12     | 
| 628df59f091142399e0689a2696f5baa | images       | 1      | 
+----------------------------------+--------------+--------+

リソース利用をテナントのクォータと結合することで、利用率を求めることが出来ます。例えば、テナントが、10個のうち1つのFloating IPを利用しているとすると、10%のFloating IP クォータを利用することになります。これを行なうことで、レポートを作ることができます。

+-----------------------------------+------------+-------------+---------------+ 
| some_tenant                                                                  | 
+-----------------------------------+------------+-------------+---------------+ 
| Resource                          | Used       | Limit       |               | 
+-----------------------------------+------------+-------------+---------------+ 
| cores                             | 1          | 20          |           5 % | 
| floating_ips                      | 1          | 10          |          10 % | 
| gigabytes                         | 12         | 1000        |           1 % | 
| images                            | 1          | 4           |          25 % | 
| injected_file_content_bytes       | 0          | 10240       |           0 % | 
| injected_file_path_bytes          | 0          | 255         |           0 % | 
| injected_files                    | 0          | 5           |           0 % | 
| instances                         | 1          | 10          |          10 % | 
| key_pairs                         | 0          | 100         |           0 % | 
| metadata_items                    | 0          | 128         |           0 % | 
| ram                               | 512        | 51200       |           1 % | 
| reservation_expire                | 0          | 86400       |           0 % | 
| security_group_rules              | 0          | 20          |           0 % | 
| security_groups                   | 0          | 10          |           0 % | 
| volumes                           | 2          | 10          |          20 % | 
+-----------------------------------+------------+-------------+---------------+

上記の出力はこのGithub (https://github.com/cybera/novac/blob/dev/libexec/novac-quota-report) にあるカスタムスクリプトを用いて作成しました。

[注記]注記

このスクリプトは特定のOpenStackインストール環境向けなので、自身の環境に適用する際には変更しなくてはいけませんが、ロジックは簡単に変更できるでしょう。

 インテリジェントなアラート

インテリジェントなアラートは運用における継続的インテグレーションの要素の一つです。例えば、以下のような方法で簡単にGlanceが起動しているかを簡単に確認できます。glance-apiglance-registryプロセスが起動していることを確認する、もしくはglace-apiが9292ポートに応答するといった方法です。

しかし、イメージサービスにイメージが正しくアップロードされたことをどのように知ればいいのでしょうか? もしかしたら、イメージサービスが保管しているイメージのディスクが満杯、もしくはS3のバックエンドがダウンしているかもしれません。簡易的なイメージアップロードを行なうことでこれをチェックすることができます。

#!/bin/bash 
# 
# assumes that resonable credentials have been stored at 
# /root/auth 
 
      
. /root/openrc 
wget https://launchpad.net/cirros/trunk/0.3.0/+download/cirros-0.3.0-x86_64-disk.img  
glance image-create --name='cirros image' --is-public=true --container-format=bare --disk-format=qcow2 < cirros-0.3.0-x8
6_64-disk.img

このスクリプトを(Nagiosのような)監視システムに組込むことで、イメージカタログのアップロードが動作していることを自動的に確認することができます。

[注記]注記

毎回テスト後にイメージを削除する必要があります。イメージサービスからイメージが削除できるかのテストにしてしまえば、さらによいです。

インテリジェントなアラートは、この章で述べられているの他のアラートよりも計画、実装にかなり時間を要します。インテリジェントなアラートを実装する流れは次のようになります。

  • 構築したクラウドにおいて一般的なアクションをレビューする

  • それらのアクションに対して自動テストを作成する

  • それらのテストをアラートシステムに組み込む

インテリジェントなアラートのその他の例としては以下があります。

  • インスタンスの起動と削除が可能か?

  • ユーザの作成は可能か?

  • オブジェクトの保存と削除は可能か?

  • ボリュームの作成と削除は可能か?

 トレンド

トレンドはどのようにクラウドが実行されているかの素晴しい見通しを与えてくれます。例えば、負荷の高い日がたまたま発生したのか、新しいコンピュートノードを追加すべきか、などです。

トレンドはアラートとは全く異なったアプローチです。アラートは0か1かの結果(チェックが成功するか失敗するか)に注目しているのに対して、トレンドはある時点での状態を定期的に記録します。十分な量が記録されれば、時系列でどのように値が変化するかを確認できます。

これまでに示した全てのアラートタイプは、トレンドレポートに利用可能です。その他のトレンドの例は以下の通りです。

  • 各コンピュートノード上のインスタンス数

  • 使用中のフレーバー

  • 使用中のボリューム数

  • 1時間あたりの Object Storage リクエスト数

  • 1時間あたりの nova-api リクエスト数

  • ストレージサービスの I/O の統計

例として、nova-apiの使用を記録することでクラウドコントローラーをスケールする必要があるかを追跡できます。nova-apiのリクエスト数に注目することにより、nova-apiプロセスを追加するか、もしくは、nova-apiを実行するための新しいサーバーを導入することまで行なうかを決定することができます。リクエストの概数を取得するには/var/log/nova/nova-api.logのINFOメッセージを検索します。

# grep INFO /var/log/nova/nova-api.log | wc

成功したリクエストを検索することで、更なる情報を取得できます。

# grep " 200 " /var/log/nova/nova-api.log | wc

このコマンドを定期的に実行し結果を記録することで、トレンドレポートを作ることができます。これにより/var/log/nova/nova-api.logの使用量が増えているのか、減っているのか、安定しているのか、を知ることができます。

collectdのようなツールはこのような情報を保管することに利用できます。collectdはこの本のスコープから外れますが、collectdでCOUNTERデータ形として結果を保存するのがよい出発点になります。より詳しい情報はcollectdのドキュメント (https://collectd.org/wiki/index.php/Data_source)を参照してください。



loading table of contents...