kvmtool bug
SergeyOvsienko opened this issue · 5 comments
SergeyOvsienko commented
Hi All!
runv version 0.8.1, commit: v0.8.1-61-g773c40b
Docker version 17.05.0-ce, build 89658be
Runv hase been started as
sudo ./runv --debug --driver kvmtool --kernel /opt/hyperstart/build/kernel --initrd /opt/hyperstart/build/hyper-initrd.img containerd
I0724 14:19:55.725148 24171 driverloader_linux.go:60] Driver "kvmtool" loaded
I0724 14:19:55.726186 24171 containerd.go:179] containerd daemon started successfully.
I0724 14:19:55.726201 24171 containerd.go:216] containerd: grpc api on /run/runv-containerd/containerd.sock
Dockerd
sudo dockerd -D -s devicemapper -l debug --containerd=/run/runv-containerd/containerd.sock --add-runtime runv=runv --default-runtime runv
After i am start busybox container
sudo docker run -ti busybox
Unable to find image 'busybox:latest' locally
latest: Pulling from library/busybox
9e87eff13613: Pull complete
Digest: sha256:2605a2c4875ce5eb27a9f7403263190cd1af31e48a2044d400320548356251c4
Status: Downloaded newer image for busybox:latest
docker: Error response from daemon: json: cannot unmarshal array into Go struct field Process.capabilities of type specs.LinuxCapabilities.
In RunV log
I0724 14:21:55.870186 24171 server.go:41] gRPC handle CreateContainer
In dockerd log
DEBU[0029] Calling POST /v1.29/containers/create
DEBU[0029] form data: {"AttachStderr":true,"AttachStdin":true,"AttachStdout":true,"Cmd":null,"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":null,"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"busybox","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":true,"StdinOnce":true,"Tty":true,"User":"","Volumes":{},"WorkingDir":""}
DEBU[0029] Calling GET /v1.29/info
DEBU[0029] Calling POST /v1.29/images/create?fromImage=busybox&tag=latest
DEBU[0029] Trying to pull busybox from https://registry-1.docker.io v2
DEBU[0031] Pulling ref from V2 registry: busybox:latest
DEBU[0031] pulling blob "sha256:9e87eff13613eed2f67b0188f8604d1bbdd3a7f5d6a4f565e8923817db65d6e5"
DEBU[0032] Downloaded 9e87eff13613 to tempfile /var/lib/docker/tmp/GetImageBlob097780392
DEBU[0032] devmapper: AddDevice START(hash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188 basehash=)
DEBU[0032] devmapper: Failed to read /var/lib/docker/devicemapper/metadata/fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188 with err: open /var/lib/docker/devicemapper/metadata/fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188: no such file or directory
DEBU[0032] devmapper: registerDevice(2, fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: AddDevice END(hash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188 basehash=)
DEBU[0032] devmapper: activateDeviceIfNeeded(fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] Start untar layer
DEBU[0032] Untar time: 0.073797027s
DEBU[0032] devmapper: UnmountDevice START(hash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: Unmount(/var/lib/docker/devicemapper/mnt/fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: Unmount done
DEBU[0032] devmapper: deactivateDevice START(fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: removeDevice START(docker-8:1-7087740-fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: removeDevice END(docker-8:1-7087740-fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: deactivateDevice END(fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: UnmountDevice END(hash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] Applied tar sha256:08c2295a7fa5c220b0f60c994362d290429ad92f6e0235509db91582809442f3 to fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188, size: 1129193
DEBU[0032] Calling POST /v1.29/containers/create
DEBU[0032] form data: {"AttachStderr":true,"AttachStdin":true,"AttachStdout":true,"Cmd":null,"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":null,"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"busybox","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":true,"StdinOnce":true,"Tty":true,"User":"","Volumes":{},"WorkingDir":""}
DEBU[0032] devmapper: AddDevice START(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init basehash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: Failed to read /var/lib/docker/devicemapper/metadata/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init with err: open /var/lib/docker/devicemapper/metadata/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init: no such file or directory
DEBU[0032] devmapper: registerDevice(3, a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: AddDevice END(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init basehash=fd304673a72f98c4ae78c28999c1eec555aadfecd6ea7165a696f563a2394188)
DEBU[0032] devmapper: activateDeviceIfNeeded(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: UnmountDevice START(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: Unmount(/var/lib/docker/devicemapper/mnt/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: Unmount done
DEBU[0032] devmapper: deactivateDevice START(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: removeDevice START(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: removeDevice END(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: deactivateDevice END(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: UnmountDevice END(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: AddDevice START(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f basehash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: Failed to read /var/lib/docker/devicemapper/metadata/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f with err: open /var/lib/docker/devicemapper/metadata/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f: no such file or directory
DEBU[0032] devmapper: registerDevice(4, a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: AddDevice END(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f basehash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f-init)
DEBU[0032] devmapper: activateDeviceIfNeeded(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] container mounted via layerStore: /var/lib/docker/devicemapper/mnt/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f/rootfs
DEBU[0032] devmapper: UnmountDevice START(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: Unmount(/var/lib/docker/devicemapper/mnt/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: Unmount done
DEBU[0032] devmapper: deactivateDevice START(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: removeDevice START(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: removeDevice END(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: deactivateDevice END(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: UnmountDevice END(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] Calling POST /v1.29/containers/1133902ccd286779a72245102b2f0d3824f8e8a0d156d635b7d81a9840bb4e47/attach?stderr=1&stdin=1&stdout=1&stream=1
DEBU[0032] attach: stdin: begin
DEBU[0032] attach: stdout: begin
DEBU[0032] attach: stderr: begin
DEBU[0032] Calling GET /v1.29/events?filters=%7B%22container%22%3A%7B%221133902ccd286779a72245102b2f0d3824f8e8a0d156d635b7d81a9840bb4e47%22%3Atrue%7D%2C%22type%22%3A%7B%22container%22%3Atrue%7D%7D
DEBU[0032] Calling POST /v1.29/containers/1133902ccd286779a72245102b2f0d3824f8e8a0d156d635b7d81a9840bb4e47/start
DEBU[0032] devmapper: activateDeviceIfNeeded(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] container mounted via layerStore: /var/lib/docker/devicemapper/mnt/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f/rootfs
DEBU[0032] Assigning addresses for endpoint loving_brahmagupta's interface on network bridge
DEBU[0032] RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])
DEBU[0032] Assigning addresses for endpoint loving_brahmagupta's interface on network bridge
DEBU[0032] Programming external connectivity on endpoint loving_brahmagupta (1b416c0f1567d82af0eb877da881ac23a36a69abf09a43dab1d9145f36454727)
ERRO[0032] Create container failed with error: json: cannot unmarshal array into Go struct field Process.capabilities of type specs.LinuxCapabilities
ERRO[0032] stream copy error: reading from a closed fifo
github.com/docker/docker/vendor/github.com/tonistiigi/fifo.(*fifo).Read
/usr/src/docker/.gopath/src/github.com/docker/docker/vendor/github.com/tonistiigi/fifo/fifo.go:142
bufio.(*Reader).fill
/usr/local/go/src/bufio/bufio.go:97
bufio.(*Reader).WriteTo
/usr/local/go/src/bufio/bufio.go:472
io.copyBuffer
/usr/local/go/src/io/io.go:380
io.Copy
/usr/local/go/src/io/io.go:360
github.com/docker/docker/pkg/pools.Copy
/usr/src/docker/.gopath/src/github.com/docker/docker/pkg/pools/pools.go:60
github.com/docker/docker/container/stream.(*Config).CopyToPipe.func1.1
/usr/src/docker/.gopath/src/github.com/docker/docker/container/stream/streams.go:121
runtime.goexit
/usr/local/go/src/runtime/asm_amd64.s:2086
DEBU[0032] attach: stdout: end
DEBU[0032] attach: stderr: end
DEBU[0032] attach: stdin: end
DEBU[0032] Closing buffered stdin pipe
DEBU[0032] Revoking external connectivity on endpoint loving_brahmagupta (1b416c0f1567d82af0eb877da881ac23a36a69abf09a43dab1d9145f36454727)
DEBU[0032] DeleteConntrackEntries purged ipv4:0, ipv6:0
DEBU[0032] Releasing addresses for endpoint loving_brahmagupta's interface on network bridge
DEBU[0032] ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)
DEBU[0032] devmapper: UnmountDevice START(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: Unmount(/var/lib/docker/devicemapper/mnt/a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: Unmount done
DEBU[0032] devmapper: deactivateDevice START(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: removeDevice START(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: removeDevice END(docker-8:1-7087740-a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: deactivateDevice END(a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
DEBU[0032] devmapper: UnmountDevice END(hash=a874f3b8603a4edf784a867942210ffef05d681a08f0600f682a59d65885b57f)
ERRO[0032] Handler for POST /v1.29/containers/1133902ccd286779a72245102b2f0d3824f8e8a0d156d635b7d81a9840bb4e47/start returned error: json: cannot unmarshal array into Go struct field Process.capabilities of type specs.LinuxCapabilities
gao-feng commented
Wow, so quickly:-)
Thanks for your try!
docker: Error response from daemon: json: cannot unmarshal array into Go struct field Process.capabilities of type specs.LinuxCapabilities.
This problem is not related to kvmtool or other hypervisor, it is caused by the old oci config and new oci spec. you should update your oci container config, simply remove Process.capabilities is fine since runv doesn't care about this field.
the below is my process config
"process": {
"terminal": true,
"user": {},
"args": [
"sh"
],
"env": [
"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
"TERM=xterm"
],
"cwd": "/",
"rlimits": [
{
"type": "RLIMIT_NOFILE",
"hard": 1024,
"soft": 1024
}
],
"noNewPrivileges": true
},
SergeyOvsienko commented
Thanks for quick answer.
I am update docker for Docker version 17.06.0-ce, build 02c1d87 and clear /var/lib/docker directory.
dpkg -l|grep kvmtool
ii kvmtool 0.20151104-1 amd64 Native Linux KVM TOOL
After this i am run sudo docker run -ti busybox
I0724 17:42:10.209946 2163 server.go:41] gRPC handle CreateContainer
I0724 17:42:10.211748 2163 hyperpod.go:456] Using kernel: ; Initrd: ; vCPU: 1; Memory 128
I0724 17:42:10.220949 2163 lkvm.go:222] SB[vm-mgXyNufJtB] find /dev/pts/12 /dev/pts/13
I0724 17:42:11.221103 2163 lkvm.go:222] SB[vm-mgXyNufJtB] find /dev/pts/12 /dev/pts/13 /dev/pts/14
I0724 17:42:11.221189 2163 vm.go:765] VM[vm-mgXyNufJtB] GetVm succeeded
I0724 17:42:11.221196 2163 hyperpod.go:468] Creating VM with default kernel config
I0724 17:42:11.221237 2163 lkvm.go:248] lkvm output:
I0724 17:42:11.221283 2163 hypervisor.go:41] SB[vm-mgXyNufJtB] watch hyperstart
I0724 17:42:11.221289 2163 hypervisor.go:44] SB[vm-mgXyNufJtB] issue VERSION request for keep-alive test
I0724 17:42:11.222700 2163 vm_console.go:56] SB[vm-mgXyNufJtB] fail to enable vmLogd: dial unix /var/run/vmlogd.sock: connect: no such file or directory
I0724 17:42:11.242161 2163 json.go:171] SB[vm-mgXyNufJtB] Wating for init messages...
I0724 17:42:11.242263 2163 json.go:446] SB[vm-mgXyNufJtB] stream socket connected
I0724 17:42:11.242806 2163 vm_console.go:68] SB[vm-mgXyNufJtB] connected to /var/run/hyper/vm-mgXyNufJtB/console.sock
I0724 17:42:11.242834 2163 vm_console.go:75] SB[vm-mgXyNufJtB] connected /var/run/hyper/vm-mgXyNufJtB/console.sock as telnet mode.
I0724 17:42:11.242990 2163 vm_console.go:91] SB[vm-mgXyNufJtB] [CNL] omit the first 128 line of console logs
I0724 17:42:11.243003 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Policy zone: DMA32
I0724 17:42:11.243008 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243014 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Kernel command line: noapic noacpi pci=conf1 reboot=k panic=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 console=ttyS0 earlyprintk=serial i8042.noaux=1 rw rootflags=trans=virtio,version=9p2000.L,cache=loose rootfstype=9p console=ttyS0 hyper_use_serial
I0724 17:42:11.243019 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243028 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] PID hash table entries: 512 (order: 0, 4096 bytes)
I0724 17:42:11.243032 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243038 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Memory: 110856K/130680K available (5140K kernel code, 604K rwdata, 1528K rodata, 992K init, 640K bss, 19824K reserved, 0K cma-reserved)
I0724 17:42:11.243047 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243051 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Hierarchical RCU implementation.
I0724 17:42:11.243056 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243060 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Build-time adjustment of leaf fanout to 64.
I0724 17:42:11.243065 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243069 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=2.
I0724 17:42:11.243073 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=2
I0724 17:42:11.243078 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NR_IRQS:4352 nr_irqs:440 16
I0724 17:42:11.243082 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Console: colour *CGA 80x25
I0724 17:42:11.243086 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] console [ttyS0] enabled
I0724 17:42:11.243090 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] console [ttyS0] enabled
I0724 17:42:11.243095 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] bootconsole [earlyser0] disabled
I0724 17:42:11.243099 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] bootconsole [earlyser0] disabled
I0724 17:42:11.243103 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] tsc: Detected 3192.672 MHz processor
I0724 17:42:11.243107 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] tsc: Marking TSC unstable due to TSCs unsynchronized
I0724 17:42:11.243112 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Calibrating delay loop (skipped) preset value.. 6385.34 BogoMIPS (lpj=3192672)
I0724 17:42:11.243117 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pid_max: default: 32768 minimum: 301
I0724 17:42:11.243122 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
I0724 17:42:11.243126 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
I0724 17:42:11.243130 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
I0724 17:42:11.243135 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
I0724 17:42:11.243140 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
I0724 17:42:11.243144 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
I0724 17:42:11.243148 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] smpboot: Max logical packages: 2
I0724 17:42:11.243152 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] smpboot: CPU 0 Converting physical 4 to logical package 0
I0724 17:42:11.243157 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] smpboot: CPU0: LKVMLKVMLKVM 06/3c (family: 0x6, model: 0x3c, stepping: 0x3)
I0724 17:42:11.243161 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Performance Events: no PMU driver, software events only.
I0724 17:42:11.243166 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] KVM setup paravirtual spinlock
I0724 17:42:11.243170 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] x86: Booted up 1 node, 1 CPUs
I0724 17:42:11.243252 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] smpboot: Total of 1 processors activated (6385.34 BogoMIPS)
I0724 17:42:11.243258 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] devtmpfs: initialized
I0724 17:42:11.243262 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] x86/mm: Memory block size: 128MB
I0724 17:42:11.243267 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
I0724 17:42:11.243271 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] futex hash table entries: 512 (order: 3, 32768 bytes)
I0724 17:42:11.243276 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NET: Registered protocol family 16
I0724 17:42:11.243280 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] cpuidle: using governor ladder
I0724 17:42:11.243284 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] cpuidle: using governor menu
I0724 17:42:11.243289 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] PCI: Using configuration type 1 for base access
I0724 17:42:11.243293 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] ACPI: Interpreter disabled.
I0724 17:42:11.243297 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] vgaarb: loaded
I0724 17:42:11.243302 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] SCSI subsystem initialized
I0724 17:42:11.243306 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] dmi: Firmware registration failed.
I0724 17:42:11.243310 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] PCI: Probing PCI hardware
I0724 17:42:11.243315 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] PCI host bridge to bus 0000:00
I0724 17:42:11.243319 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]
I0724 17:42:11.243323 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pci_bus 0000:00: root bus resource [mem 0x00000000-0x7fffffffff]
I0724 17:42:11.243328 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
I0724 17:42:11.243332 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] clocksource: Switched to clocksource kvm-clock
I0724 17:42:11.243336 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pnp: PnP ACPI: disabled
I0724 17:42:11.243340 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NET: Registered protocol family 2
I0724 17:42:11.243345 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
I0724 17:42:11.243350 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
I0724 17:42:11.243355 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] TCP: Hash tables configured (established 1024 bind 1024)
I0724 17:42:11.243359 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] UDP hash table entries: 256 (order: 1, 8192 bytes)
I0724 17:42:11.243367 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
I0724 17:42:11.243372 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NET: Registered protocol family 1
I0724 17:42:11.243376 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Trying to unpack rootfs image as initramfs...
I0724 17:42:11.243380 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Freeing initrd memory: 6840K (ffff880007900000 - ffff880007fae000)
I0724 17:42:11.243385 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] platform rtc_cmos: registered platform RTC device (no PNP device found)
I0724 17:42:11.243389 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2e053f72b27, max_idle_ns: 440795293829 ns
I0724 17:42:11.243394 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] workingset: timestamp_bits=37 max_order=15 bucket_order=0
I0724 17:42:11.243398 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] SGI XFS with ACLs, security attributes, no debug enabled
I0724 17:42:11.243402 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] 9p: Installing v9fs 9p2000 file system support
I0724 17:42:11.243406 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
I0724 17:42:11.243411 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] io scheduler noop registered
I0724 17:42:11.243415 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] io scheduler cfq registered (default)
I0724 17:42:11.243419 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
I0724 17:42:11.243424 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
I0724 17:42:11.243428 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] virtio-pci 0000:00:00.0: virtio_pci: leaving for legacy driver
I0724 17:42:11.243433 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] virtio-pci 0000:00:01.0: virtio_pci: leaving for legacy driver
I0724 17:42:11.243437 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
I0724 17:42:11.243453 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
I0724 17:42:11.243458 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a U6_16550A
I0724 17:42:11.243462 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] serial8250: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a U6_16550A
I0724 17:42:11.243466 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] serial8250: ttyS2 at I/O 0x3e8 (irq = 4, base_baud = 115200) is a U6_16550A
I0724 17:42:11.243481 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] brd: module loaded
I0724 17:42:11.243485 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] loop: module loaded
I0724 17:42:11.243490 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
I0724 17:42:11.243494 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] rtc_cmos rtc_cmos: only 24-hr supported
I0724 17:42:11.243498 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Initializing XFRM netlink socket
I0724 17:42:11.243502 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NET: Registered protocol family 10
I0724 17:42:11.243507 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] NET: Registered protocol family 17
I0724 17:42:11.243511 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Bridge firewalling registered
I0724 17:42:11.243515 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] 9pnet: Installing 9P2000 support
I0724 17:42:11.243520 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] registered taskstats version 1
I0724 17:42:11.243525 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] hctosys: unable to open rtc device (rtc0)
I0724 17:42:11.243529 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Freeing unused kernel memory: 992K (ffffffff81899000 - ffffffff81991000)
I0724 17:42:11.243533 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Write protecting the kernel read-only data: 8192k
I0724 17:42:11.243538 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Freeing unused kernel memory: 988K (ffff880001509000 - ffff880001600000)
I0724 17:42:11.243542 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Freeing unused kernel memory: 520K (ffff88000177e000 - ffff880001800000)
I0724 17:42:11.243547 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243551 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] <**********************************************************************
I0724 17:42:11.243555 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] < Hyperstart Version: 0.8.1, commit: v0.8.1-2-gfaef420
I0724 17:42:11.243559 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] <**********************************************************************
I0724 17:42:11.243564 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] uptime 0.29 0.01
I0724 17:42:11.243568 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243573 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] create directory /dev/pts
I0724 17:42:11.243577 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] probe /sys/bus/pci/devices//0000:00:00.0
I0724 17:42:11.243581 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] found vendor: 1af4 ID: 9
I0724 17:42:11.243585 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] probe /sys/bus/pci/devices//0000:00:02.0
I0724 17:42:11.243589 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] found vendor: 1af4 ID: 1
I0724 17:42:11.243595 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] random: fast init done
I0724 17:42:11.243599 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] probe /sys/bus/pci/devices//0000:00:01.0
I0724 17:42:11.243603 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] found vendor: 1af4 ID: 9
I0724 17:42:11.243607 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] cannot find vsock device
I0724 17:42:11.243612 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] fail to setup hyper control serial port
I0724 17:42:11.243616 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Kernel panic - not syncing: Attempted to kill init! exitcode=0x00000000
I0724 17:42:11.243620 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL]
I0724 17:42:11.243624 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] CPU: 0 PID: 1 Comm: init Not tainted 4.9.23-hyper #1
I0724 17:42:11.243629 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] 0000000000000000 ffffffff812b1000 ffff8800068af300 ffffc9000003beb8
I0724 17:42:11.243659 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] ffffffff810dadfd 0000000000000010 ffffc9000003bec8 ffffc9000003be68
I0724 17:42:11.243666 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] ffff8800076176a0 0000000000000000 ffff8800068bb9d0 0000000000000000
I0724 17:42:11.243670 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Call Trace:
I0724 17:42:11.243675 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff812b1000>] ? dump_stack+0x5c/0x7c
I0724 17:42:11.243679 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff810dadfd>] ? panic+0xd6/0x208
I0724 17:42:11.243685 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff81056b96>] ? do_exit+0xa66/0xa70
I0724 17:42:11.243689 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff81056c04>] ? do_group_exit+0x34/0xa0
I0724 17:42:11.243693 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff81056c7b>] ? SyS_exit_group+0xb/0x10
I0724 17:42:11.243697 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] [<ffffffff8150133b>] ? entry_SYSCALL_64_fastpath+0x1e/0xad
I0724 17:42:11.243702 2163 vm_console.go:96] SB[vm-mgXyNufJtB] [CNL] Kernel Offset: disabled
I0724 17:42:19.966256 2163 lkvm.go:325] read failed: read /dev/pts/14: input/output error
I0724 17:42:19.966304 2163 lkvm.go:331] REACH the END of io copy
I0724 17:42:19.966256 2163 lkvm.go:325] read failed: read /dev/pts/13: input/output error
I0724 17:42:19.966339 2163 lkvm.go:331] REACH the END of io copy
I0724 17:42:19.966272 2163 lkvm.go:325] read failed: read /dev/pts/12: input/output error
I0724 17:42:19.966347 2163 lkvm.go:331] REACH the END of io copy
I0724 17:42:19.966283 2163 lkvm.go:251] read lkvm output failed: read /dev/ptmx: input/output error
I0724 17:42:19.966372 2163 lkvm.go:277] close socket to pty
I0724 17:42:19.966394 2163 vm_console.go:113] Input byte chan closed, close the output string chan
I0724 17:42:19.966406 2163 vm_console.go:98] SB[vm-mgXyNufJtB] console output end
E0724 17:43:11.221511 2163 hypervisor.go:37] SB[vm-mgXyNufJtB] watch hyperstart timeout
I0724 17:43:11.222546 2163 json.go:93] SB[vm-mgXyNufJtB] close jsonBasedHyperstart
E0724 17:43:11.222596 2163 json.go:601] SB[vm-mgXyNufJtB] get hyperstart API version error: hyperstart closed
W0724 17:43:11.222619 2163 hypervisor.go:47] SB[vm-mgXyNufJtB] keep-alive test end with error: hyperstart closed
E0724 17:43:11.222651 2163 vm_states.go:226] SB[vm-mgXyNufJtB] Start POD failed: hyperstart closed
I0724 17:43:11.222695 2163 vm_states.go:249] SB[vm-mgXyNufJtB] poweroff vm based on command: vm.Kill()
I0724 17:43:11.222713 2163 lkvm.go:380] SB[vm-mgXyNufJtB] shutdown
I0724 17:43:11.222758 2163 hypervisor.go:23] SB[vm-mgXyNufJtB] main event loop got message 13(ERROR_INIT_FAIL)
E0724 17:43:11.222795 2163 vm_states.go:289] SB[vm-mgXyNufJtB] watch hyperstart timeout
E0724 17:43:11.222816 2163 vm_states.go:246] SB[vm-mgXyNufJtB] Shutting down because of an exception: %!(EXTRA string=connection to vm broken)
I0724 17:43:11.222832 2163 vm_states.go:249] SB[vm-mgXyNufJtB] poweroff vm based on command: connection to vm broken
I0724 17:43:11.222847 2163 lkvm.go:380] SB[vm-mgXyNufJtB] shutdown
I0724 17:43:11.226325 2163 json.go:426] SB[vm-mgXyNufJtB] tty chan closed, quit sent goroutine
E0724 17:43:11.226488 2163 json.go:401] read tty data failed
E0724 17:43:11.226539 2163 json.go:458] SB[vm-mgXyNufJtB] tty socket closed, quit the reading goroutine: read unix @->/var/run/hyper/vm-mgXyNufJtB/tty.sock: use of closed network connection
I0724 17:43:11.226780 2163 lkvm.go:321] read end of file
I0724 17:43:11.226841 2163 lkvm.go:331] REACH the END of io copy
I0724 17:43:11.226970 2163 lkvm.go:277] close socket to pty
E0724 17:43:11.239174 2163 hyperpod.go:500] StartPod fail, response: &api.ResultBase{Id:"vm-mgXyNufJtB", Success:false, ResultMessage:"got failed event when wait init message"}
I0724 17:43:11.239244 2163 supervisor.go:231] createHyperPod() returns
I0724 17:43:11.239259 2163 supervisor.go:155] reap container 7a0a7306dfa16e77eeda2ec3ae9ed5264a8cf252323d254bbb98d25b4946f779 processId init
I0724 17:43:11.240194 2163 context.go:197] SB[vm-mgXyNufJtB] VmContext Close()
I0724 17:43:11.240267 2163 hypervisor.go:31] SB[vm-mgXyNufJtB] main event loop exiting
What am I doing wrong?
SergeyOvsienko commented
sudo lsmod |grep -i vhost_vsock
vhost_vsock 16384 0
vmw_vsock_virtio_transport_common 28672 1 vhost_vsock
vsock 36864 2 vhost_vsock,vmw_vsock_virtio_transport_common
vhost 45056 1 vhost_vsock
sergey@sergey-All-Series:~$ uname -a
Linux sergey-All-Series 4.8.0-58-generic #63~16.04.1-Ubuntu SMP Mon Jun 26 18:08:51 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
SergeyOvsienko commented
I am update hyperstart
hyperstart 0.8.1
prefix: /usr/local
with-vbox: no
with-aarch64: no
with-kmodules: yes
vsock-support: yes
compiler: gcc
cflags: -g -O2
suid cflags:
ldflags:
suid ldflags:
systemd unit path: /lib/systemd/system
Work fine.
I think it's worth adding to the documentation about kernel 4.8+ and hyperstart 0.8.1
SergeyOvsienko commented
After destroy vm
root 5058 0.0 0.0 60216 3940 pts/10 S+ 18:09 0:00 | \_ sudo ./runv --debug --driver kvmtool --kernel /opt/hyperstart/build/kernel --initrd /opt/hyperstart/build/hyper-i
root 5059 0.6 0.2 1115344 33508 pts/10 Sl+ 18:09 0:12 | \_ ./runv --debug --driver kvmtool --kernel /opt/hyperstart/build/kernel --initrd /opt/hyperstart/build/hyper-in
root 5314 0.0 0.0 0 0 pts/10 Z+ 18:10 0:00 | \_ [runv] <defunct>
root 5687 0.0 0.0 0 0 pts/10 Z+ 18:11 0:00 | \_ [runv] <defunct>
Growing number of zombies