Vagrant上でubuntu/xenial32, ubuntu/xenial64が動作しない

追記: 原因と解決策は次の記事にある.

環境

Host:

Guest:

症状

Vagrantubuntu/xenial64(あるいはubuntu/xenial32)を起動した所,

  • 起動後まもなく,root filesystemがread-onlyになる
  • 動いている間も動作が遅い

という症状に遭遇した.

ログファイルを見ると,

[  105.513000] sd 2:0:0:0: [sda] tag#7 Medium access timeout failure. Offlining disk!
[  108.734234] sd 2:0:0:0: rejecting I/O to offline device
[  108.793265] sd 2:0:0:0: rejecting I/O to offline device
[  108.793318] blk_update_request: I/O error, dev sda, sector 1994752
[  108.793323] Buffer I/O error on device sda1, logical block 249088
[  108.793326] Buffer I/O error on device sda1, logical block 249089
[  108.793327] Buffer I/O error on device sda1, logical block 249090
...

となり,sdaへのアクセスがタイムアウトしたことによりディスクを切り離してしまい,その後一切のアクセスができなくなっている.

ubuntu/trusty64などやVitualBoxに直接Ubuntu Serverをインストールした場合は発生しない症状である.

Workaround 1

I/Oがタイムアウトする,ということでVMの起動直後に,sdaのタイムアウトの調整を試みたところ,タイムアウトからread-onlyになる症状は発生しなくなった.

sudo sh -c 'echo 120 > /sys/block/sda/device/timeout'

しかし,ディスクI/Oが時々,極めて時間がかかる.次の記録は/dev/urandomから256MB読んでファイルに書き込む操作を繰り返した際のものであるが,2回目のみ長時間かかっている.そもそもddとtimeの報告している時間が一致していない.

ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 29.5976 s, 9.1 MB/s

real	0m29.623s
user	0m0.000s
sys	0m17.756s
ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 174.663 s, 1.5 MB/s

real	6m26.321s
user	0m0.004s
sys	0m17.716s
ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 33.1649 s, 8.1 MB/s

real	0m33.195s
user	0m0.000s
sys	0m17.620s

Workaround 2

ubuntu/trusty64と異なりubuntu/xenial64では,SATAコントローラではなくSCSIコントローラが用いられていることに気づいた.

ubuntu/trusty64

ubuntu/xenial64

VirtualBoxの設定画面からSCSIコントローラを削除し,SATAコントローラに変更した所,タイムアウトからread-onlyになる症状は発生しなくなった.

ワークアラウンドとして,vagrant boxのbox.ovfを書き換えてSATAコントローラを利用する方法も検討した.

--- .vagrant.d/boxes/ubuntu-VAGRANTSLASH-xenial64/20160429.0.0/virtualbox/box.ovf.orig	2016-05-02 22:24:42.490411586 +0900
+++ .vagrant.d/boxes/ubuntu-VAGRANTSLASH-xenial64/20160429.0.0/virtualbox/box.ovf	2016-05-02 22:33:01.721795537 +0900
@@ -79,11 +79,12 @@
       </Item>
       <Item>
         <rasd:Address>0</rasd:Address>
-        <rasd:Description>SCSI Controller</rasd:Description>
-        <rasd:ElementName>SCSI Controller 0</rasd:ElementName>
+        <rasd:Caption>sataController0</rasd:Caption>
+        <rasd:Description>SATA Controller</rasd:Description>
+        <rasd:ElementName>SATA Controller 0</rasd:ElementName>
         <rasd:InstanceID>3</rasd:InstanceID>
-        <rasd:ResourceSubType>VirtualSCSI</rasd:ResourceSubType>
-        <rasd:ResourceType>6</rasd:ResourceType>
+        <rasd:ResourceSubType>AHCI</rasd:ResourceSubType>
+        <rasd:ResourceType>20</rasd:ResourceType>
       </Item>
       <Item>
         <rasd:Address>1</rasd:Address>

しばらく動作させると停止する事こそ無いものの次のようなエラーメッセージがdmesgに出力されていた.

[  138.725547] ata3.00: exception Emask 0x0 SAct 0x7f00013c SErr 0x0 action 0x6 frozen
[  138.767307] ata3.00: failed command: WRITE FPDMA QUEUED
[  138.767783] ata3.00: cmd 61/00:10:00:d0:1f/08:00:00:00:00/40 tag 2 ncq 1048576 out
                        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[  138.769023] ata3.00: status: { DRDY }
...
[  141.449344] ata3: hard resetting link
[  141.773423] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[  141.773579] ata3.00: configured for UDMA/133
[  141.773583] ata3.00: device reported invalid CHS sector 0
[  141.773584] ata3.00: device reported invalid CHS sector 0
...
[  141.773604] sd 2:0:0:0: [sda] tag#1 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_TIMEOUT
[  141.773606] sd 2:0:0:0: [sda] tag#1 CDB: Write(10) 2a 00 00 1f 80 00 00 08 00 00
[  141.773608] blk_update_request: I/O error, dev sda, sector 2064384
[  142.050589] EXT4-fs warning (device sda1): ext4_end_bio:329: I/O error -5 writing to inode 56795 (offset 0 size 8388608 starting block 258304)
[  142.050592] Buffer I/O error on device sda1, logical block 257792
...

Workaround 1と同様,ディスクI/Oが時々,極めて時間がかかる.次の記録は/dev/urandomから256MB読んでファイルに書き込む操作を繰り返した際のものである.Workaround 1と比較すると,時間がかかる処理の割合は増えているようだ.

ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 281.666 s, 953 kB/s

real	5m45.765s
user	0m0.000s
sys	0m17.744s
ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 170.685 s, 1.6 MB/s

real	4m21.259s
user	0m0.000s
sys	0m18.000s
ubuntu@ubuntu-xenial:~$ time dd if=/dev/urandom of=./file bs=1M count=256
256+0 records in
256+0 records out
268435456 bytes (268 MB, 256 MiB) copied, 48.634 s, 5.5 MB/s

real	2m57.844s
user	0m0.000s
sys	0m17.620s

まとめ

タイムアウトや速度低下が発生する症状から,ゲストOSとVirtualBoxの間のHDDの通信が消失するなどしている可能性が考えられる.

二つのワークアラウンドにより最低限動作させることは出来るようになったが,未だ根本的な解決はできていない.

追記: 原因が判明したため,解決策を次の記事に掲載した.