VagrantでVMを起動させるとVBoxHeadlessがCPUを100%使用し続けることがある

以前、あるシステムをVagrantとVirtualBoxを使用して構築しました。
1つの物理マシン上に、多いもので20数台のVMを起動しているのですが、VMの起動時に何らかの契機(原因不明)により、正常に起動できず、他のVMも起動されないというエラーが発生することがありました。

エラーの原因となったVMのVBoxHeadlessプロセスが、CPUを100%使用し続ける状態になっており、正常に起動していないため、Vagrantが起動のTimeoutエラーを返すという現象でした。

滅多に発生する現象ではないのですが、一度発生してしまうと、VMやホストOSの再起動では解決しません。
数日前に、この現象が再発したので解決方法を探り、解決することができましたので備忘録として残しておきます。

環境

Linux Kernel

3.5.0-23-generic #35~precise1-Ubuntu

ディストリビューション

Ubuntu 12.04.4 LTS (Ubuntu Server)

VirtualBox

Oracle VM VirtualBox Manager 4.1.12_Ubuntu

Vagrant

Vagrant 1.3.5

各々のバージョンが少し古いせいで、この現象が発生する可能性もあります。
許容されるのであれば、全て最新のバージョンにすることが望ましいです。

現象の詳細

VagrantでVirtualBoxのVMを起動する際、以下のようなメッセージが出力されます。

[node1] Clearing any previously set forwarded ports...
[node1] Fixed port collision for 22 => 2206. Now on port 2207.
[node1] Creating shared folders metadata...
[node1] Clearing any previously set network interfaces...
[node1] Preparing network interfaces based on configuration...
[node1] Forwarding ports...
[node1] -- 22 => 2207 (adapter 1)
[node1] Running 'pre-boot' VM customizations...
[node1] Booting VM...
[node1] Waiting for machine to boot. This may take a few minutes...

本現象が発生すると、上記メッセージのまましばらく停止した後、VagrantのTimeoutが発生し、起動エラーとなります。
topでプロセスを確認すると、以下のように表示され、かなりのCPU時間が消費されていました。

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
10987 hoge       20   0 1236m  55m  29m S  100  0.3 225:44.62 /usr/lib/virtualbox/VBoxHeadless

VMイメージの破損や何かしらの原因でエラーが発生しているのなら(まだ)いいのですが、Vagrantが出す起動Timeoutのエラーメッセージ以外は、まるでエラーなど発生していないかのように何のメッセージも出ません。
対象のVirtualBoxのノードのVBox.logを確認してもさっぱり分かりませんでした。

原因

Grubが起動し、起動対象のOSイメージの選択画面で停止していることが原因でした…。
他のVM達は正常に起動するのに、停止する前までは正常に起動していたのに、何らかの原因で選択画面で止まってしまうようです。

解決方法

VMのプロセスのVirtualBoxのVRDP(仮想リモートプレイプロトコル)を有効にする。
GUIのある他のマシンから、リモートデスクトップ接続で接続する。
OSを選択し、起動したら、シャットダウンコマンドで終了する。

一度OSを選択して起動してやれば、次回からは選択画面で停止することなく、自動的に起動します。
なお、解決方法の手順2、3の説明は省略します。

VMのVRDPの有効化

Extension Packのインストール

古いVirtualBoxにはVBoxVRDPなどのコマンドは付属されていないため、Extension Packをインストールする必要があります。

Extension Packの確認

以下のコマンドを実行し、Extension Packsが0と表示された場合はインストールしてください。

$ VBoxManage list extpacks
Extension Packs: 0

以下のように表示された場合は、既にインストールされています。

$ VBoxManage list extpacks
Extension Packs: 1
Pack no. 0:   Oracle VM VirtualBox Extension Pack
Version:      4.1.12
Revision:     77245
Description:  USB 2.0 Host Controller, VirtualBox RDP, PXE ROM with E1000 support.
VRDE Module:  VBoxVRDP
Usable:       true

ファイルの取得

以下のコマンドで、ホストOSに入っているVirtualBox用のExtension Packを取得します。

$ wget http://download.virtualbox.org/virtualbox/4.1.12/Oracle_VM_VirtualBox_Extension_Pack-4.1.12-77245.vbox-extpack

各バージョン向けに用意されていますので、以下のURLから、使用しているVirtualBox用に用意されたExtension Packを取得してください。

VirtualBoxのOld Builds

インストール

ファイル名は各バージョンごとに合わせてください。

$ sudo VBoxManage extpack install ./Oracle_VM_VirtualBox_Extension_Pack-4.1.12-77245.vbox-extpack

VMのUUIDの取得

上で、topコマンドでプロセスを確認しましたが、topコマンドに-cフラグを与えて実行します。
そうすると、以下のようにプロセスの引数も確認できるので、–startvmの後のUUIDを取得します。
(以下の例では、bb37e50a-df85-4105-8eb8-4d57df406633。)

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
10987 hoge       20   0 1236m  55m  29m S  100  0.3 225:44.62 /usr/lib/virtualbox/VBoxHeadless --comment node1_1436513818 --startvm bb37e50a-df85-4105-8eb8-4d57df406633 --vrde config

ここでは、topコマンドを使用していますが、UUIDが特定できさえすれば何でも構いません(VBoxManage list runningvms等々)。

VRDPの設定

以下のコマンドを実行し、VMのVRDPを有効化します(最後をvrdp onとすると、deprecatedだと怒られます)。

$ VBoxManage controlvm 84654a25-9f0e-4b2b-a2a0-0eae20cf6a5e vrde on

実行すると対象のVMのVBox.logファイルに、以下のようなメッセージが出力されます。

00:04:50.020 VRDP: TCP server listening on port 3389.

netstatコマンドで確認すると、ホストOS上のポート3389が開き、接続を待ち受けていることが確認できます。

tcp        0      0 0.0.0.0:3389            0.0.0.0:*               LISTEN

ここまでの手順で、VRDPの有効化は終わりました。
あとは、WindowsやLinuxのリモートデスクトップアプリケーションを使用して、ホストOSに接続してください。接続すると画面が表示されます。

ここまでの手順で、ホストOSにGUIがインストールされていない環境であっても、リモートデスクトップで画面が表示できるようになります。
調査開始時点では、まさかGrubで止まっているなんて想像もしませんでしたが、無事に解決することができました。

環境