KMC 京都マイクロコンピュータ株式会社

KVMが使えるようにファイルのPermissionを変更する

emulator-x86のデフォルトの設定ではKVMを使用するか否かは自動設定になっていて、KVMを使用しようとして失敗したらそのままKVMを無効にして起動するようになっています。そのため、最初はKVMが効いていないことに気がついていませんでした。

以下のように明示的にKVMを指定して起動してみると

$ emulator-x86 -qemu -enable-kvm 

emulator: WARNING: system partition size adjusted to match image file (130 MB > 66 MB)

Could not access KVM kernel module: Permission denied
ko:failed to initialize KVM

KVMの初期化に失敗しました。ソースコードを調べると /dev/kvmのopenで失敗しているようです。

sudoで実行すればroot権限で実行されるのですが、そうすると環境変数が引き継がれません。そこで、以下のようにしてemulator-x86の実行ファイルのgidをkvmに変更し、gidの権限で実行されるようにモードを変更しました。

$ ls -l out/host/linux-x86/bin/emulator-x86 
-rwxr-xr-x 1 koba koba 7478953 2011-07-22 16:39 out/host/linux-x86/bin/emulator-x86
$ ls -l /dev/kvm 
crw-rw----+ 1 root kvm 10, 232 2011-07-26 11:18 /dev/kvm
$ sudo chgrp kvm out/host/linux-x86/bin/emulator-x86 
$ sudo chmod g+s out/host/linux-x86/bin/emulator-x86 
$ ls -l out/host/linux-x86/bin/emulator-x86 
-rwxr-sr-x 1 koba kvm 7478953 2011-07-22 16:39 out/host/linux-x86/bin/emulator-x86

これでもう一度試してみると

$ emulator-x86 -qemu -enable-kvm &

起動しました。

KVMの有無での比較

KVMを有効にしたところ、起動のときに真っ黒の画面の時間が長くなりましたが、Androidのブートアニメーションの時間は短くなりました。ログを見ると面白いことがわかりました。

Kernel boot log of emulator-x86 -qemu -enable-kvm

Android log of emulator-x86 -qemu -enable-kvm

Kernel boot log of emulator-x86 -qemu -disable-kvm

Android log of emulator-x86 -qemu -disable-kvm

Kernel boot log of emulator-arm

Android log of emulator-arm

KVM on でのdmesg

<6>[    0.150613] Freeing unused kernel memory: 256k freed
<3>[    0.170340] init: cannot open '/initlogo.rle'
<6>[    0.207056] yaffs: dev is 32505856 name is "mtdblock0"
<6>[    0.207126] yaffs: passed flags ""
<4>[    0.207181] yaffs: Attempting MTD mount on 31.0, "mtdblock0"
<4>[    9.989004] yaffs_read_super: isCheckpointed 0
<4>[   10.004521] save exit: isCheckpointed 1
<6>[   10.004634] yaffs: dev is 32505857 name is "mtdblock1"
<6>[   10.004703] yaffs: passed flags ""
<4>[   10.004769] yaffs: Attempting MTD mount on 31.1, "mtdblock1"
<4>[   14.715207] yaffs_read_super: isCheckpointed 0
<6>[   14.715517] yaffs: dev is 32505858 name is "mtdblock2"
<6>[   14.715780] yaffs: passed flags ""
<4>[   14.716040] yaffs: Attempting MTD mount on 31.2, "mtdblock2"
<4>[   14.821412] yaffs_read_super: isCheckpointed 0

yaffsのマウントで10秒以上の時間がかかっています。

KVM offではそうなりません。

<6>[    0.406806] Freeing unused kernel memory: 256k freed
<3>[    0.547972] init: cannot open '/initlogo.rle'
<6>[    0.620893] yaffs: dev is 32505856 name is "mtdblock0"
<6>[    0.621001] yaffs: passed flags ""
<4>[    0.621072] yaffs: Attempting MTD mount on 31.0, "mtdblock0"
<4>[    0.840707] yaffs_read_super: isCheckpointed 0
<4>[    0.852857] save exit: isCheckpointed 1
<6>[    0.853350] yaffs: dev is 32505857 name is "mtdblock1"
<6>[    0.853367] yaffs: passed flags ""
<4>[    0.853379] yaffs: Attempting MTD mount on 31.1, "mtdblock1"
<4>[    0.965432] yaffs_read_super: isCheckpointed 0
<6>[    0.966197] yaffs: dev is 32505858 name is "mtdblock2"
<6>[    0.966209] yaffs: passed flags ""
<4>[    0.966221] yaffs: Attempting MTD mount on 31.2, "mtdblock2"
<4>[    0.974583] yaffs_read_super: isCheckpointed 0

KVM onでのAndroidの起動ログです。

I/Zygote  (  750): ...preloaded 1829 classes in 2421ms.
E/Zygote  (  750): setreuid() failed. errno: 30
D/dalvikvm(  750): GC_EXPLICIT freed 18K, 50% free 2585K/5123K, external 0K/0K, paused 4ms
I/Zygote  (  750): Preloading resources...
D/dalvikvm(  750): GC_EXTERNAL_ALLOC freed <1K, 50% free 2587K/5123K, external 0K/0K, paused 3ms
D/dalvikvm(  750): GC_EXPLICIT freed 16K, 49% free 2629K/5123K, external 435K/521K, paused 3ms
D/dalvikvm(  750): GC_EXTERNAL_ALLOC freed 7K, 49% free 2635K/5123K, external 516K/521K, paused 4ms
I/Zygote  (  750): ...preloaded 51 resources in 162ms.
I/Zygote  (  750): ...preloaded 15 resources in 4ms.
D/dalvikvm(  750): GC_EXPLICIT freed 14K, 49% free 2658K/5123K, external 716K/1038K, paused 4ms
D/dalvikvm(  750): GC_EXPLICIT freed 7K, 49% free 2650K/5123K, external 716K/1038K, paused 3ms
D/dalvikvm(  750): GC_EXPLICIT freed 1K, 49% free 2649K/5123K, external 716K/1038K, paused 0ms
I/dalvikvm(  750): System server process 816 has been created
I/Zygote  (  750): Accepting command socket connections

同じところをKVM offの場合です。

I/Zygote  (  750): ...preloaded 1829 classes in 5485ms.
E/Zygote  (  750): setreuid() failed. errno: 30
D/dalvikvm(  750): GC_EXPLICIT freed 18K, 50% free 2586K/5123K, external 0K/0K, paused 33ms
I/Zygote  (  750): Preloading resources...
D/dalvikvm(  750): GC_EXTERNAL_ALLOC freed <1K, 50% free 2588K/5123K, external 0K/0K, paused 32ms
D/dalvikvm(  750): GC_EXPLICIT freed 16K, 49% free 2629K/5123K, external 435K/521K, paused 24ms
D/dalvikvm(  750): GC_EXTERNAL_ALLOC freed 7K, 49% free 2635K/5123K, external 516K/521K, paused 32ms
I/Zygote  (  750): ...preloaded 51 resources in 402ms.
I/Zygote  (  750): ...preloaded 15 resources in 21ms.
D/dalvikvm(  750): GC_EXPLICIT freed 14K, 49% free 2658K/5123K, external 716K/1038K, paused 33ms
D/dalvikvm(  750): GC_EXPLICIT freed 7K, 49% free 2651K/5123K, external 716K/1038K, paused 32ms
D/dalvikvm(  750): GC_EXPLICIT freed 1K, 49% free 2650K/5123K, external 716K/1038K, paused 22ms
I/dalvikvm(  750): System server process 816 has been created
I/Zygote  (  750): Accepting command socket connections

preloadにかかった時間が倍くらい違います。GCの時間では8倍くらい違います。

なお、ARMのemulatorはKVM offの方と同じくらいの時間がかかります。

どうもKVM onの時には通常の実行はかなり高速化されたけれどもディスクI/Oのアクセスが遅いのが足を引っ張っているようです。ファイルシステムをKVMに特化したものに置き換えればディスクI/Oの速度は改善されると思います。

現段階のemulator-x86はまだ開発途中のものです。また、DalvikVMのJITはx86用のものはまだありません。次のSDKではこれらが改善されて登場するのでしょうか。