仮想マシンの VMware Tools デバッグログについて

使ってる方は少ないと思いますが、VMware Tools のデバッグログを有効化することも可能です。

VMware Tools のデバッグログを一体何に使うのか疑問に思う方も少なくないのではないかと思います。

デバッグログは、主にトラブルシューティング、または 開発関連で VMware Tools を介して処理しなければならない時に、ゲスト OS (仮想マシン) 側でどのようにメッセージのやり取りが行われるか、その動きを確かめるときに使います。

簡単な例を挙げますと 仮想マシンに VMware Tools をインストールすることによって、以下のように ゲスト OS の再起動ゲスト OS のシャットダウン メニュー が使えるようになります。

VMware Tools の電源操作メニュー (Open VM Tools インストール後)

VM 電源操作 (VMware Tools インストール前)

VMware Tools の電源操作メニュー (Open VM Tools インストール後)

VM 電源操作 (VMware Tools インストール後)

すなわち、VMware Tools を入れることによって、ゲスト OS にログインしなくても、vCenter Client を使って仮想マシンに対して、より簡単に再起動、または シャットダウン出来るようになる訳ですが、

この操作を、vCenter を操作するためのクライアントを使わずに、

例えば、vSphere SDK for Perl、または Power CLI といった API が提供する機能を用いて、仮想マシンに対して 再起動、または シャットダウンするように命令を発行した際に、VMware Tools のデバッグログを確認することで、API からのメッセージをちゃんと受信したか、受信したメッセージは適切に処理されたか等、どのようにメッセイジのやり取りが行われるか確認することができます。

VMware Tools のデバッグログ有効化

VMware Tools のデバッグログは、致命的なエラー等 余程のことがない限り生成されることはないため、デフォルトで無効という認識で良いですが、問題解決・情報収集目的でログを取得しなければならない時は、意図的にデバッグログを有効にする必要があります。

デバッグログを出力するためには、tools.conf という名前で設定ファイルを新規作成し、決まった場所に配置する必要があります。 (Windows / Linux 等、OS によって配置先が異なります)

以下の例では、debug レベルのログを /var/log/vmwaretools.log に出力させるように設定しています。

/etc/vmware-tools/tools.conf
1
2
3
4
5
[logging]
log=true
vmsvc.level=debug
vmsvc.handler=file+
vmsvc.data=/var/log/vmwaretools.log

ちなみに、vmsvc.handler=file+file+ は、既存の /var/log/vmwaretools.log ファイルにログを追加出力 (APPEND) するオプションです。

VMware Tools サービスの再起動は不要で、コンフィグファイルを保持するとリアルタイムでデバッグログが流れ続けるようになります。

また、各パラメータに設定する詳細オプション (OS 別 tools.conf の配置先、ログレベル、syslog ファシリティ設定 等) については、以下の URL をご確認ください。

ゲスト OS の種類配置先
Windows XPWindows Server 2000Windows Server 2003C:\Documents and Settings\All Users\Application Data\VMware\VMware Tools\tools.conf
Windows VistaWindows 7Windows 8Windows Server 2008Windows Server 2012C:\ProgramData\VMware\VMware Tools\tools.conf
LinuxSolarisFreeBSD/etc/vmware-tools/tools.conf
Mac OS X/Library/Application Support/VMware Tools/tools.conf

各パラメータ設定できるオプションだけ簡単にまとめると、

  • level[none | critical | error | warning | message | info | debug] ※ ログ詳細順
  • handler[file | file+ | vmx | syslog | std | outputdebugstring]syslog、std は Linux 専用、outputdebugstring は Windows 専用std : 標準出力させるオプションvmx : ESXi / ESX ホスト上の仮想マシンのフォルダ内の vmware.log にログ出力
  • datahandler=file、 handler=file+ の時だけ有効handler に file、または file+ がセットされた時のログ保存先 (ファイルパス)
  • maxOldLogFileshandler=file、 handler=file+ の時だけ有効ログローテーション 世代数、設定する場合は 0 より大きい値を設定することデフォルト : 10
  • maxLogSizehandler=file、 handler=file+ の時だけ有効0 にするとログローテーションが無効になるデフォルト : 5 (MB 単位)
  • facilityhandler=syslog の時だけ有効[LOG_DAEMON | LOG_USER | LOG_LOCAL[0-7]]デフォルト : LOG_USER

出力例 その1. 通常のログ

以下は、デバッグログを有効にした後、単純にほったらかしにした時の出力結果です。

VMware Tools デバッグログ : 通常のログ
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
# tail -f /var/log/vmwaretools.log
[ 4月 20 13:36:36.039] [   debug] [guestinfo] Setting guest uptime to '510430203'
[ 4月 20 13:36:36.039] [   debug] [guestinfo] Entered update vmdb: 7.
[ 4月 20 13:36:36.039] [   debug] [vmsvc] RpcChannel: Sending: 26 bytes
[ 4月 20 13:36:36.039] [   debug] [vmsvc] VSockChan: Sending request for conn 8,  reqLen=26
[ 4月 20 13:36:36.039] [   debug] [vmsvc] SimpleSock: Sent 58 bytes from socket 8
[ 4月 20 13:36:36.039] [   debug] [vmsvc] SimpleSock: Recved 4 bytes from socket 8
[ 4月 20 13:36:36.039] [   debug] [vmsvc] SimpleSock: Recved 14 bytes from socket 8
[ 4月 20 13:36:36.039] [   debug] [vmsvc] VSockOut: recved 2 bytes for conn 8
[ 4月 20 13:36:36.039] [   debug] [vmsvc] RpcChannel: Recved 0 bytes
[ 4月 20 13:36:36.039] [   debug] [guestinfo] Returning after updating guest information: 7
[ 4月 20 13:36:38.871] [   debug] [guestinfo] Entered guest info stats gather.
[ 4月 20 13:36:38.872] [   debug] [guestinfo] Entered update vmdb: 8.
[ 4月 20 13:36:38.872] [   debug] [guestinfo] Sending GuestMemInfo message.
[ 4月 20 13:36:38.872] [   debug] [vmsvc] RpcChannel: Sending: 354 bytes
[ 4月 20 13:36:38.872] [   debug] [vmsvc] VSockChan: Sending request for conn 8,  reqLen=354
[ 4月 20 13:36:38.872] [   debug] [vmsvc] SimpleSock: Sent 386 bytes from socket 8
[ 4月 20 13:36:38.872] [   debug] [vmsvc] SimpleSock: Recved 4 bytes from socket 8
[ 4月 20 13:36:38.872] [   debug] [vmsvc] SimpleSock: Recved 14 bytes from socket 8
[ 4月 20 13:36:38.872] [   debug] [vmsvc] VSockOut: recved 2 bytes for conn 8
[ 4月 20 13:36:38.872] [   debug] [vmsvc] RpcChannel: Recved 0 bytes
[ 4月 20 13:36:38.872] [   debug] [guestinfo] GuestMemInfo sent successfully.
[ 4月 20 13:36:38.872] [   debug] [guestinfo] Returning after updating guest information: 8
[ 4月 20 13:36:40.296] [   debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[ 4月 20 13:36:45.206] [   debug] [vmsvc] RpcIn: received 5 bytes, content:"ping\00"
[ 4月 20 13:36:45.207] [   debug] [vmsvc] RpcIn: sending 3 bytes
[ 4月 20 13:36:45.357] [   debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[ 4月 20 13:36:50.367] [   debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[ 4月 20 13:36:55.468] [   debug] [vmsvc] RpcIn: received 0 bytes, empty TCLO poll
[ 4月 20 13:36:57.973] [   debug] [vmsvc] RpcIn: received 24 bytes, content:"Set_Option broadcastIP 1"
[ 4月 20 13:36:57.973] [   debug] [vmtoolsd] Setting option 'broadcastIP' to '1'.
[ 4月 20 13:36:57.973] [   debug] [vmsvc] RpcChannel: Sending: 34 bytes
[ 4月 20 13:36:57.973] [   debug] [vmsvc] VSockChan: Sending request for conn 8,  reqLen=34
[ 4月 20 13:36:57.973] [   debug] [vmsvc] SimpleSock: Sent 66 bytes from socket 8
[ 4月 20 13:36:57.974] [   debug] [vmsvc] SimpleSock: Recved 4 bytes from socket 8
[ 4月 20 13:36:57.974] [   debug] [vmsvc] SimpleSock: Recved 14 bytes from socket 8
[ 4月 20 13:36:57.974] [   debug] [vmsvc] VSockOut: recved 2 bytes for conn 8
[ 4月 20 13:36:57.974] [   debug] [vmsvc] RpcChannel: Recved 0 bytes
[ 4月 20 13:36:57.974] [   debug] [vmsvc] RpcIn: sending 3 bytes
・・・

出力例 その2. API を用いて VM に対して再起動コマンドを発行した時のログ

以下は、API (vSphere SDK for Perl) サーバ側で my-vm-01 という仮想マシンを再起動させた後、仮想マシン側で確認した時の VMware Tools のデバッグログです。

API 側 : VM 再起動コマンド実行
1
2
# vmware-cmd --config ./TARGET-ESX-01.conf "[DATASTOR-01] my-vm-01/my-vm-01.vmx" reset soft
reset() = 1
VM 側 : VMware Tools ログ確認
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
# tail -f /var/log/vmwaretools.log
[12月 12 16:39:27.164] [   debug] [vmsvc] RpcIn: received 9 bytes, content:"OS_Reboot"
[12月 12 16:39:27.164] [   debug] [powerops] State change: OS_Reboot
[12月 12 16:39:27.164] [ message] [powerops] Executing script: '/etc/vmware-tools/poweroff-vm-default'
[12月 12 16:39:27.172] [   debug] [vmsvc] RpcIn: sending 3 bytes
[12月 12 16:39:27.202] [ message] [powerops] Script exit code: 0, success = 1
[12月 12 16:39:27.202] [   debug] [powerops] State change complete, success = 1.
[12月 12 16:39:27.202] [   debug] [vmsvc] RpcChannel: Sending: 32 bytes
[12月 12 16:39:27.202] [   debug] [vmsvc] VSockChan: Sending request for conn 8,  reqLen=32
[12月 12 16:39:27.203] [   debug] [vmsvc] SimpleSock: Sent 64 bytes from socket 8
[12月 12 16:39:27.203] [   debug] [vmsvc] SimpleSock: Recved 4 bytes from socket 8
[12月 12 16:39:27.203] [   debug] [vmsvc] SimpleSock: Recved 14 bytes from socket 8
[12月 12 16:39:27.203] [   debug] [vmsvc] VSockOut: recved 2 bytes for conn 8
[12月 12 16:39:27.203] [   debug] [vmsvc] RpcChannel: Recved 0 bytes
[12月 12 16:39:27.203] [ message] [powerops] Initiating reboot.
・・・

VMware Tools のデバッグログ無効化

VMware Tools のデバッグログを無効にするには、

  • tools.conf ファイルを削除するか
  • tools.conf の中身をすべてコメントアウトするか
  • tools.conf 内の log パラメータに false をセットします (log=false)
無効化 その1 (tools.conf 削除)
1
2
# rm /etc/vmware-tools/tools.conf
rm: 通常ファイル `/etc/vmware-tools/tools.conf' を削除しますか? y
無効化 その2 (全てコメントアウト) : /etc/vmware-tools/tools.conf
1
2
3
4
5
#[logging]
#log=true
#vmsvc.level=debug
#vmsvc.handler=file+
#vmsvc.data=/var/log/vmwaretools.log
無効化 その3 (log=false にする) : /etc/vmware-tools/tools.conf
1
2
3
4
5
6
[logging]
#log=true
log=false
vmsvc.level=debug
vmsvc.handler=file+
vmsvc.data=/var/log/vmwaretools.log

同じく、tools.conf の設定変更後、再起動は不要です。

VMware Tools のログを無効にすると以下のように、Config file reloaded とうメッセージが表示され、ログ出力は停止します。

VMware Tools ログ出力を無効にした後のログ出力結果
1
2
3
# tail /etc/vmware-tools/tools.conf
・・・
[ 4月 21 13:40:33.741] [   debug] [vmtoolsd] Config file reloaded.

終わりに

普段あまり使う機会はないかもしれませんが、vSphere の仮想環境を触ってるといずれ使わないと行けない時が (たまに) あるので、こんなこともできるんだなーと軽く覚えておく位で良いと思います。

以上、VMware Tools ゲスト OS のデバッグログ有効化 でした。