hyperhq / runv Goto Github PK

View Code? Open in Web Editor NEW

827.0 43.0 129.0 13.4 MB

Hypervisor-based Runtime for OCI

License: Apache License 2.0

Shell 8.23% Go 90.74% Makefile 0.37% M4 0.44% C 0.21%

oci hypervisor containers

runv's People

Contributors

Stargazers

Watchers

Forkers

laijs gao-feng feiskyer cofyc guijianfeng gnawux justincormack coolljt0725 zju-sel weizhang555 bergwolf xiaomuqiao sqleejan yaozengzeng gbriones1 xlgao-zju ptptptptptpt resouer macrosheep thed00de moypray hukeping wrouesnel helen-xie tiansen rchirakk crazykev gaocegege jinfenw intelsdi-x 0xh0b0 veyesecurity cybertan rbramwell zofuthan sboeuf xiaoshao pombredanne fogongzi tvelocity zdf8122 mrwangxc chenmin46 duzhanyuan hicest pol-no yyb196 nuaays xiaochunyn zhaoxuqiang ace-tang allencloud harche galaxydata kyasuda2003 sameo weichen81 czm4514 avldya husterwan teawater gbraad mbrukman jeswin rezroo yangwanli2017 alexxnica kryndex mendickxiao islinwb xiaoxubeii acidburn0zzz cmingxu jongwu lukw00heck lizcly pingp76 claymodel c1dx kincl jackzhanghk th3architect chuanchang cloveryl yyyeerbo rocky-nupt bluebreezecf iruze lcfang h2non fangwenqi alexfeng123 terry1504 ateleshev jimoosciuc the-cc-dev nkwilson gssxd xiaoruiguo carletes

runv's Issues

Rbd volume not working for qemu driver

Monitors and secrets not setted up for rbd volume

default runv initrd file is inconsistent with readme

README said the deault initrd file should be ./initrd.img not ./initrd

https://github.com/hyperhq/runv/blob/master/README.md#run

this will cause runv fail to start oci container.

Unable to start a container with docker

Docker Version: v1.11
QEMU Version: QEMU emulator version 2.2.0
Step:
1.sudo runv-containerd --kernel=kernel --initrd hyper-initrd.img --debug
2.sudo docker daemon --containerd=/run/runv-containerd/containerd.sock
3.sudo docker run -d ubuntu sleep 1000
the Output of runv-containerd:

Qemu Driver Loaded
I0511 17:52:39.343186   29001 main.go:167] containerd: grpc api on /run/runv-containerd/containerd.sock
I0511 17:52:59.041576   29001 server.go:31] gRPC handle CreateContainer
I0511 17:52:59.043094   29001 vm.go:178] hyperHandlePodEvent pod pod-oSlkcTtGSM, vm vm-mLXMShFlsw
I0511 17:52:59.043161   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 23(COMMAND_RUN_POD)
I0511 17:52:59.043177   29001 vm_states.go:556] got spec, prepare devices
I0511 17:52:59.043299   29001 qemu_process.go:63] cmdline arguments: -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -cpu host -kernel kernel -initrd hyper-initrd.img -append console=ttyS0 panic=1 no_timer_check -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,driftfix=slew -no-reboot -display none -boot strict=on -m 128 -smp 1 -qmp unix:/var/run/hyper/vm-mLXMShFlsw/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-mLXMShFlsw/console.sock,server,nowait -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -chardev socket,id=charch0,path=/var/run/hyper/vm-mLXMShFlsw/hyper.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0 -chardev socket,id=charch1,path=/var/run/hyper/vm-mLXMShFlsw/tty.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1 -fsdev local,id=virtio9p,path=/var/run/hyper/vm-mLXMShFlsw/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir
I0511 17:52:59.043350   29001 vm_states.go:72] initial vm spec: {
        "hostname": "93f7ec670178",
        "containers": [],
        "shareDir": "share_dir"
    }
I0511 17:52:59.043377   29001 context.go:210] VM vm-mLXMShFlsw: state change from INIT to 'STARTING'
I0511 17:52:59.043386   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 11(EVENT_DEV_SKIP)
I0511 17:52:59.043395   29001 vm_states.go:585] device ready, could run pod.
I0511 17:52:59.044016   29001 qemu_process.go:74] starting daemon with pid: 29053
I0511 17:52:59.103813   29001 init_comm.go:29] connected to /var/run/hyper/vm-mLXMShFlsw/console.sock
I0511 17:52:59.103925   29001 init_comm.go:36] connected /var/run/hyper/vm-mLXMShFlsw/console.sock as telnet mode.
I0511 17:52:59.103813   29001 init_comm.go:109] Wating for init messages...
I0511 17:52:59.103972   29001 init_comm.go:72] trying to read 8 bytes
I0511 17:52:59.103813   29001 tty.go:157] tty socket connected
I0511 17:52:59.104000   29001 tty.go:100] tty: trying to read 12 bytes
I0511 17:52:59.103813   29001 qmp_handler.go:167] connected to /var/run/hyper/vm-mLXMShFlsw/qmp.sock
I0511 17:52:59.104030   29001 qmp_handler.go:177] begin qmp init...
I0511 17:52:59.110586   29001 tty.go:441] Input byte chan closed, close the output string chan
I0511 17:52:59.110632   29001 init_comm.go:46] console output end
E0511 17:52:59.110678   29001 qmp_handler.go:181] get qmp welcome failed: read unix @->/var/run/hyper/vm-mLXMShFlsw/qmp.sock: read: connection reset by peer
E0511 17:52:59.111079   29001 qmp_handler.go:361] QMP initialize failed
I0511 17:52:59.111111   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 41(ERROR_INIT_FAIL)
E0511 17:52:59.111128   29001 vm_states.go:503] read unix @->/var/run/hyper/vm-mLXMShFlsw/qmp.sock: read: connection reset by peer
E0511 17:52:59.111144   29001 vm_states.go:358] Shutting down because of an exception: Fail during init pod running environment
I0511 17:52:59.111168   29001 context.go:210] VM vm-mLXMShFlsw: state change from STARTING to 'TERMINATING'
E0511 17:52:59.110680   29001 init_comm.go:75] read init data failed
E0511 17:52:59.111204   29001 init_comm.go:113] read init message failed... read unix @->/var/run/hyper/vm-mLXMShFlsw/hyper.sock: read: connection reset by peer
I0511 17:52:59.111240   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 41(ERROR_INIT_FAIL)
W0511 17:52:59.111258   29001 vm_states.go:494] got unexpected event during terminating
I0511 17:52:59.111258   29001 vm.go:259] Get the response from VM, VM id is vm-mLXMShFlsw!
I0511 17:52:59.111283   29001 hyperpod.go:88] StartPod fail: QEMU response data is nil
I0511 17:52:59.111293   29001 supervisor.go:168] createHyperPod() returns
E0511 17:52:59.110693   29001 tty.go:103] read tty data failed
I0511 17:52:59.111388   29001 tty.go:164] tty socket closed, quit the reading goroutine read unix @->/var/run/hyper/vm-mLXMShFlsw/tty.sock: read: connection reset by peer
I0511 17:52:59.111421   29001 tty.go:131] tty chan closed, quit sent goroutine
I0511 17:52:59.111438   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 43(ERROR_INTERRUPTED)
I0511 17:52:59.111470   29001 vm_states.go:813] Connection interrupted while terminating
I0511 17:53:09.111283   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 3(EVENT_VM_TIMEOUT)
W0511 17:53:09.111312   29001 vm_states.go:810] VM did not exit in time, try to stop it
E0511 17:53:09.111324   29001 vm_states.go:367] Shutting down because of an exception: vm terminating timeout
I0511 17:53:19.111579   29001 qemu_process.go:24] kill Qemu... 29053
I0511 17:53:19.111613   29001 hypervisor.go:29] vm vm-mLXMShFlsw: main event loop got message 2(EVENT_VM_KILL)
I0511 17:53:19.111624   29001 vm_states.go:788] Got VM force killed message, go to cleaning up
I0511 17:53:19.111633   29001 vm_states.go:34] VM has exit...
I0511 17:53:19.111728   29001 context.go:197] no more device to release/remove/umount, quit

runv-containerd can't start container

I'll paste logs directly here.

Try to run docker run -tid --net none busybox sh with runv-containerd, it reports error:

I0526 14:41:14.338046   21767 server.go:31] gRPC handle CreateContainer
I0526 14:41:14.338853   21767 vm.go:179] hyperHandlePodEvent pod pod-qBJGmhcgni, vm vm-DNlnLYiACB
I0526 14:41:14.338910   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 21(COMMAND_RUN_POD)
I0526 14:41:14.338932   21767 vm_states.go:449] got spec, prepare devices
I0526 14:41:14.338960   21767 vm_states.go:67] initial vm spec: {
        "hostname": "d6a01446059e",
        "containers": [],
        "shareDir": "share_dir"
    }
I0526 14:41:14.338983   21767 context.go:211] VM vm-DNlnLYiACB: state change from INIT to 'STARTING'
I0526 14:41:14.338995   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 10(EVENT_DEV_SKIP)
I0526 14:41:14.339004   21767 vm_states.go:476] device ready, could run pod.
I0526 14:41:14.339068   21767 qemu_process.go:63] cmdline arguments: -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -cpu host -kernel /var/lib/hyper/kernel -initrd /var/lib/hyper/hyper-initrd.img -append console=ttyS0 panic=1 no_timer_check -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,driftfix=slew -no-reboot -display none -boot strict=on -m 128 -smp 1 -qmp unix:/var/run/hyper/vm-DNlnLYiACB/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-DNlnLYiACB/console.sock,server,nowait -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -chardev socket,id=charch0,path=/var/run/hyper/vm-DNlnLYiACB/hyper.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0 -chardev socket,id=charch1,path=/var/run/hyper/vm-DNlnLYiACB/tty.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1 -fsdev local,id=virtio9p,path=/var/run/hyper/vm-DNlnLYiACB/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir
I0526 14:41:14.339894   21767 qemu_process.go:74] starting daemon with pid: 22766
I0526 14:41:14.359240   21767 init_comm.go:133] Wating for init messages...
I0526 14:41:14.359346   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:14.359240   21767 init_comm.go:53] connected to /var/run/hyper/vm-DNlnLYiACB/console.sock
I0526 14:41:14.359376   21767 init_comm.go:60] connected /var/run/hyper/vm-DNlnLYiACB/console.sock as telnet mode.
I0526 14:41:14.359302   21767 tty.go:144] tty socket connected
I0526 14:41:14.359418   21767 tty.go:87] tty: trying to read 12 bytes
I0526 14:41:14.359311   21767 qmp_handler.go:167] connected to /var/run/hyper/vm-DNlnLYiACB/qmp.sock
I0526 14:41:14.359445   21767 qmp_handler.go:177] begin qmp init...
I0526 14:41:14.372537   21767 qmp_handler.go:186] got qmp welcome, now sending command qmp_capabilities
I0526 14:41:14.372584   21767 qmp_handler.go:201] waiting for response
I0526 14:41:14.372760   21767 qmp_handler.go:103] got a message {"return": {}}
I0526 14:41:14.372789   21767 qmp_handler.go:210] got for response
I0526 14:41:14.372802   21767 qmp_handler.go:213] QMP connection initialized
I0526 14:41:14.372831   21767 qmp_handler.go:346] QMP initialzed, go into main QMP loop
I0526 14:41:14.372844   21767 qmp_handler.go:137] Begin receive QMP message
I0526 14:41:15.096072   21767 init_comm.go:68] [console] Initializing cgroup subsys cpuset
I0526 14:41:15.096351   21767 init_comm.go:68] [console] Initializing cgroup subsys cpu
I0526 14:41:15.096677   21767 init_comm.go:68] [console] Initializing cgroup subsys cpuacct
I0526 14:41:15.097871   21767 init_comm.go:68] [console] Linux version 4.4.7-hyper+ (bergwolf@vmfarm) (gcc version 5.2.1 20151010 (Ubuntu 5.2.1-22ubuntu2) ) #10 SMP Wed May 4 17:03:36 CST 2016
I0526 14:41:15.098326   21767 init_comm.go:68] [console] Command line: console=ttyS0 panic=1 no_timer_check
I0526 14:41:15.098814   21767 init_comm.go:68] [console] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
I0526 14:41:15.099452   21767 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'
I0526 14:41:15.099955   21767 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'
I0526 14:41:15.100463   21767 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'
I0526 14:41:15.101263   21767 init_comm.go:68] [console] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
I0526 14:41:15.101670   21767 init_comm.go:68] [console] x86/fpu: Using 'eager' FPU context switches.
I0526 14:41:15.102022   21767 init_comm.go:68] [console] e820: BIOS-provided physical RAM map:
I0526 14:41:15.102572   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
I0526 14:41:15.103151   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
I0526 14:41:15.103718   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
I0526 14:41:15.104270   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffdfff] usable
I0526 14:41:15.104830   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000007ffe000-0x0000000007ffffff] reserved
I0526 14:41:15.105403   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
I0526 14:41:15.105972   21767 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
I0526 14:41:15.106331   21767 init_comm.go:68] [console] NX (Execute Disable) protection: active
I0526 14:41:15.106516   21767 init_comm.go:68] [console] SMBIOS 2.4 present.
I0526 14:41:15.106749   21767 init_comm.go:68] [console] Hypervisor detected: KVM
I0526 14:41:15.107200   21767 init_comm.go:68] [console] e820: last_pfn = 0x7ffe max_arch_pfn = 0x400000000
I0526 14:41:15.107766   21767 init_comm.go:68] [console] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- WT  
I0526 14:41:15.108464   21767 init_comm.go:68] [console] found SMP MP-table at [mem 0x000f64b0-0x000f64bf] mapped at [ffff8800000f64b0]
I0526 14:41:15.108796   21767 init_comm.go:68] [console] RAMDISK: [mem 0x07dda000-0x07feffff]
I0526 14:41:15.109232   21767 init_comm.go:68] [console] ACPI: Early table checksum verification disabled
I0526 14:41:15.109673   21767 init_comm.go:68] [console] ACPI: RSDP 0x00000000000F6330 000014 (v00 BOCHS )
I0526 14:41:15.110398   21767 init_comm.go:68] [console] ACPI: RSDT 0x0000000007FFF688 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
I0526 14:41:15.111117   21767 init_comm.go:68] [console] ACPI: FACP 0x0000000007FFEBDA 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
I0526 14:41:15.111839   21767 init_comm.go:68] [console] ACPI: DSDT 0x0000000007FFE040 000B9A (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
I0526 14:41:15.112168   21767 init_comm.go:68] [console] ACPI: FACS 0x0000000007FFE000 000040
I0526 14:41:15.112890   21767 init_comm.go:68] [console] ACPI: SSDT 0x0000000007FFEC4E 0009C2 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
I0526 14:41:15.113606   21767 init_comm.go:68] [console] ACPI: APIC 0x0000000007FFF610 000078 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
I0526 14:41:15.113868   21767 init_comm.go:68] [console] No NUMA configuration found
I0526 14:41:15.114407   21767 init_comm.go:68] [console] Faking a node at [mem 0x0000000000000000-0x0000000007ffdfff]
I0526 14:41:15.114862   21767 init_comm.go:68] [console] NODE_DATA(0) allocated [mem 0x07dc8000-0x07dd9fff]
I0526 14:41:15.115246   21767 init_comm.go:68] [console] kvm-clock: Using msrs 4b564d01 and 4b564d00
I0526 14:41:15.115710   21767 init_comm.go:68] [console] kvm-clock: cpu 0, msr 0:7ffd001, primary cpu clock
I0526 14:41:15.116153   21767 init_comm.go:68] [console] kvm-clock: using sched offset of 712495973 cycles
I0526 14:41:15.117065   21767 init_comm.go:68] [console] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
I0526 14:41:15.117190   21767 init_comm.go:68] [console] Zone ranges:
I0526 14:41:15.117686   21767 init_comm.go:68] [console]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
I0526 14:41:15.118172   21767 init_comm.go:68] [console]   DMA32    [mem 0x0000000001000000-0x0000000007ffdfff]
I0526 14:41:15.118336   21767 init_comm.go:68] [console]   Normal   empty
I0526 14:41:15.118636   21767 init_comm.go:68] [console] Movable zone start for each node
I0526 14:41:15.118869   21767 init_comm.go:68] [console] Early memory node ranges
I0526 14:41:15.119364   21767 init_comm.go:68] [console]   node   0: [mem 0x0000000000001000-0x000000000009efff]
I0526 14:41:15.119862   21767 init_comm.go:68] [console]   node   0: [mem 0x0000000000100000-0x0000000007ffdfff]
I0526 14:41:15.120433   21767 init_comm.go:68] [console] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffdfff]
I0526 14:41:15.120707   21767 init_comm.go:68] [console] ACPI: PM-Timer IO Port: 0x608
I0526 14:41:15.121154   21767 init_comm.go:68] [console] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
I0526 14:41:15.121700   21767 init_comm.go:68] [console] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
I0526 14:41:15.122205   21767 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
I0526 14:41:15.122735   21767 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
I0526 14:41:15.123266   21767 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
I0526 14:41:15.123816   21767 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
I0526 14:41:15.124362   21767 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
I0526 14:41:15.124821   21767 init_comm.go:68] [console] Using ACPI (MADT) for SMP configuration information
I0526 14:41:15.125190   21767 init_comm.go:68] [console] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
I0526 14:41:15.125721   21767 init_comm.go:68] [console] e820: [mem 0x08000000-0xfeffbfff] available for PCI devices
I0526 14:41:15.126068   21767 init_comm.go:68] [console] Booting paravirtualized kernel on KVM
I0526 14:41:15.126965   21767 init_comm.go:68] [console] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
I0526 14:41:15.127583   21767 init_comm.go:68] [console] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_ids:1
I0526 14:41:15.128258   21767 init_comm.go:68] [console] PERCPU: Embedded 31 pages/cpu @ffff880007a00000 s89496 r8192 d29288 u2097152
I0526 14:41:15.128519   21767 init_comm.go:68] [console] KVM setup async PF for cpu 0
I0526 14:41:15.128827   21767 init_comm.go:68] [console] kvm-stealtime: cpu 0, msr 7a0d480
I0526 14:41:15.129486   21767 init_comm.go:68] [console] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 32135
I0526 14:41:15.129667   21767 init_comm.go:68] [console] Policy zone: DMA32
I0526 14:41:15.130178   21767 init_comm.go:68] [console] Kernel command line: console=ttyS0 panic=1 no_timer_check
I0526 14:41:15.130631   21767 init_comm.go:68] [console] PID hash table entries: 512 (order: 0, 4096 bytes)
I0526 14:41:15.131811   21767 init_comm.go:68] [console] Memory: 118064K/130672K available (4306K kernel code, 548K rwdata, 1400K rodata, 860K init, 756K bss, 12608K reserved, 0K cma-reserved)
I0526 14:41:15.132107   21767 init_comm.go:68] [console] Hierarchical RCU implementation.
I0526 14:41:15.132505   21767 init_comm.go:68] [console]    Build-time adjustment of leaf fanout to 64.
I0526 14:41:15.132979   21767 init_comm.go:68] [console]    RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=1.
I0526 14:41:15.133521   21767 init_comm.go:68] [console] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
I0526 14:41:15.133778   21767 init_comm.go:68] [console] NR_IRQS:4352 nr_irqs:256 16
I0526 14:41:15.134038   21767 init_comm.go:68] [console] Console: colour *CGA 80x25
I0526 14:41:15.134256   21767 init_comm.go:68] [console] console [ttyS0] enabled
I0526 14:41:15.134616   21767 init_comm.go:68] [console] tsc: Detected 3092.974 MHz processor
I0526 14:41:15.135329   21767 init_comm.go:68] [console] Calibrating delay loop (skipped) preset value.. 6185.94 BogoMIPS (lpj=3092974)
I0526 14:41:15.135685   21767 init_comm.go:68] [console] pid_max: default: 32768 minimum: 301
I0526 14:41:15.135972   21767 init_comm.go:68] [console] ACPI: Core revision 20150930
I0526 14:41:15.137372   21767 init_comm.go:68] [console] ACPI: 2 ACPI AML tables successfully acquired and loaded
I0526 14:41:15.137971   21767 init_comm.go:68] [console] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
I0526 14:41:15.138605   21767 init_comm.go:68] [console] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
I0526 14:41:15.139180   21767 init_comm.go:68] [console] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
I0526 14:41:15.139742   21767 init_comm.go:68] [console] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
I0526 14:41:15.140263   21767 init_comm.go:68] [console] Initializing cgroup subsys io
I0526 14:41:15.140572   21767 init_comm.go:68] [console] Initializing cgroup subsys memory
I0526 14:41:15.140914   21767 init_comm.go:68] [console] Initializing cgroup subsys devices
I0526 14:41:15.141236   21767 init_comm.go:68] [console] Initializing cgroup subsys freezer
I0526 14:41:15.141550   21767 init_comm.go:68] [console] Initializing cgroup subsys net_cls
I0526 14:41:15.141910   21767 init_comm.go:68] [console] Initializing cgroup subsys perf_event
I0526 14:41:15.142206   21767 init_comm.go:68] [console] Initializing cgroup subsys pids
I0526 14:41:15.142510   21767 init_comm.go:68] [console] Initializing cgroup subsys debug
I0526 14:41:15.143028   21767 init_comm.go:68] [console] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8
I0526 14:41:15.143528   21767 init_comm.go:68] [console] Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0
I0526 14:41:15.154587   21767 init_comm.go:68] [console] Freeing SMP alternatives memory: 20K (ffffffff816f6000 - ffffffff816fb000)
I0526 14:41:15.157946   21767 init_comm.go:68] [console] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
I0526 14:41:15.158836   21767 init_comm.go:68] [console] smpboot: CPU0: Intel(R) Core(TM) i5-2400 CPU @ 3.10GHz (family: 0x6, model: 0x2a, stepping: 0x7)
I0526 14:41:15.159543   21767 init_comm.go:68] [console] Performance Events: 16-deep LBR, SandyBridge events, Intel PMU driver.
I0526 14:41:15.160197   21767 init_comm.go:68] [console] perf_event_intel: PEBS disabled due to CPU errata, please upgrade microcode
I0526 14:41:15.160483   21767 init_comm.go:68] [console] ... version:                2
I0526 14:41:15.160760   21767 init_comm.go:68] [console] ... bit width:              48
I0526 14:41:15.161027   21767 init_comm.go:68] [console] ... generic registers:      8
I0526 14:41:15.161424   21767 init_comm.go:68] [console] ... value mask:             0000ffffffffffff
I0526 14:41:15.161830   21767 init_comm.go:68] [console] ... max period:             000000007fffffff
I0526 14:41:15.162100   21767 init_comm.go:68] [console] ... fixed-purpose events:   3
I0526 14:41:15.162496   21767 init_comm.go:68] [console] ... event mask:             00000007000000ff
I0526 14:41:15.163006   21767 init_comm.go:68] [console] x86: Booted up 1 node, 1 CPUs
I0526 14:41:15.163534   21767 init_comm.go:68] [console] smpboot: Total of 1 processors activated (6185.94 BogoMIPS)
I0526 14:41:15.164210   21767 init_comm.go:68] [console] devtmpfs: initialized
I0526 14:41:15.166616   21767 init_comm.go:68] [console] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
I0526 14:41:15.167098   21767 init_comm.go:68] [console] NET: Registered protocol family 16
I0526 14:41:15.167470   21767 init_comm.go:68] [console] cpuidle: using governor ladder
I0526 14:41:15.167742   21767 init_comm.go:68] [console] cpuidle: using governor menu
I0526 14:41:15.168048   21767 init_comm.go:68] [console] ACPI: bus type PCI registered
I0526 14:41:15.168568   21767 init_comm.go:68] [console] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
I0526 14:41:15.169020   21767 init_comm.go:68] [console] PCI: Using configuration type 1 for base access
I0526 14:41:15.169754   21767 init_comm.go:68] [console] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off
I0526 14:41:15.170685   21767 init_comm.go:68] [console] ACPI: Added _OSI(Module Device)
I0526 14:41:15.171000   21767 init_comm.go:68] [console] ACPI: Added _OSI(Processor Device)
I0526 14:41:15.171338   21767 init_comm.go:68] [console] ACPI: Added _OSI(3.0 _SCP Extensions)
I0526 14:41:15.171758   21767 init_comm.go:68] [console] ACPI: Added _OSI(Processor Aggregator Device)
I0526 14:41:15.172760   21767 init_comm.go:68] [console] ACPI: Interpreter enabled
I0526 14:41:15.172990   21767 init_comm.go:68] [console] ACPI: (supports S0 S5)
I0526 14:41:15.173339   21767 init_comm.go:68] [console] ACPI: Using IOAPIC for interrupt routing
I0526 14:41:15.174126   21767 init_comm.go:68] [console] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
I0526 14:41:15.176737   21767 init_comm.go:68] [console] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
I0526 14:41:15.177294   21767 init_comm.go:68] [console] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
I0526 14:41:15.177822   21767 init_comm.go:68] [console] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
I0526 14:41:15.178182   21767 init_comm.go:68] [console] acpiphp: Slot [2] registered
I0526 14:41:15.178466   21767 init_comm.go:68] [console] acpiphp: Slot [3] registered
I0526 14:41:15.178747   21767 init_comm.go:68] [console] acpiphp: Slot [4] registered
I0526 14:41:15.179044   21767 init_comm.go:68] [console] acpiphp: Slot [5] registered
I0526 14:41:15.179329   21767 init_comm.go:68] [console] acpiphp: Slot [6] registered
I0526 14:41:15.179625   21767 init_comm.go:68] [console] acpiphp: Slot [7] registered
I0526 14:41:15.179909   21767 init_comm.go:68] [console] acpiphp: Slot [8] registered
I0526 14:41:15.180200   21767 init_comm.go:68] [console] acpiphp: Slot [9] registered
I0526 14:41:15.180498   21767 init_comm.go:68] [console] acpiphp: Slot [10] registered
I0526 14:41:15.180789   21767 init_comm.go:68] [console] acpiphp: Slot [11] registered
I0526 14:41:15.181079   21767 init_comm.go:68] [console] acpiphp: Slot [12] registered
I0526 14:41:15.181371   21767 init_comm.go:68] [console] acpiphp: Slot [13] registered
I0526 14:41:15.181677   21767 init_comm.go:68] [console] acpiphp: Slot [14] registered
I0526 14:41:15.181964   21767 init_comm.go:68] [console] acpiphp: Slot [15] registered
I0526 14:41:15.182261   21767 init_comm.go:68] [console] acpiphp: Slot [16] registered
I0526 14:41:15.182555   21767 init_comm.go:68] [console] acpiphp: Slot [17] registered
I0526 14:41:15.182855   21767 init_comm.go:68] [console] acpiphp: Slot [18] registered
I0526 14:41:15.183140   21767 init_comm.go:68] [console] acpiphp: Slot [19] registered
I0526 14:41:15.183452   21767 init_comm.go:68] [console] acpiphp: Slot [20] registered
I0526 14:41:15.183746   21767 init_comm.go:68] [console] acpiphp: Slot [21] registered
I0526 14:41:15.184043   21767 init_comm.go:68] [console] acpiphp: Slot [22] registered
I0526 14:41:15.184334   21767 init_comm.go:68] [console] acpiphp: Slot [23] registered
I0526 14:41:15.184629   21767 init_comm.go:68] [console] acpiphp: Slot [24] registered
I0526 14:41:15.184927   21767 init_comm.go:68] [console] acpiphp: Slot [25] registered
I0526 14:41:15.185238   21767 init_comm.go:68] [console] acpiphp: Slot [26] registered
I0526 14:41:15.185526   21767 init_comm.go:68] [console] acpiphp: Slot [27] registered
I0526 14:41:15.185823   21767 init_comm.go:68] [console] acpiphp: Slot [28] registered
I0526 14:41:15.186118   21767 init_comm.go:68] [console] acpiphp: Slot [29] registered
I0526 14:41:15.186416   21767 init_comm.go:68] [console] acpiphp: Slot [30] registered
I0526 14:41:15.186714   21767 init_comm.go:68] [console] acpiphp: Slot [31] registered
I0526 14:41:15.187007   21767 init_comm.go:68] [console] PCI host bridge to bus 0000:00
I0526 14:41:15.187549   21767 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
I0526 14:41:15.188091   21767 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
I0526 14:41:15.188701   21767 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
I0526 14:41:15.189310   21767 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x08000000-0xfebfffff window]
I0526 14:41:15.189727   21767 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [bus 00-ff]
I0526 14:41:15.193661   21767 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
I0526 14:41:15.194169   21767 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
I0526 14:41:15.194749   21767 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
I0526 14:41:15.195265   21767 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
I0526 14:41:15.196274   21767 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
I0526 14:41:15.196869   21767 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
I0526 14:41:15.215000   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
I0526 14:41:15.215553   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
I0526 14:41:15.216107   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
I0526 14:41:15.216659   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
I0526 14:41:15.217115   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
I0526 14:41:15.217703   21767 init_comm.go:68] [console] ACPI: Enabled 16 GPEs in block 00 to 0F
I0526 14:41:15.217965   21767 init_comm.go:68] [console] vgaarb: loaded
I0526 14:41:15.218279   21767 init_comm.go:68] [console] SCSI subsystem initialized
I0526 14:41:15.218596   21767 init_comm.go:68] [console] PCI: Using ACPI for IRQ routing
I0526 14:41:15.219229   21767 init_comm.go:68] [console] clocksource: Switched to clocksource kvm-clock
I0526 14:41:15.219529   21767 init_comm.go:68] [console] pnp: PnP ACPI init
I0526 14:41:15.220161   21767 init_comm.go:68] [console] pnp: PnP ACPI: found 5 devices
I0526 14:41:15.227208   21767 init_comm.go:68] [console] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
I0526 14:41:15.227556   21767 init_comm.go:68] [console] NET: Registered protocol family 2
I0526 14:41:15.228223   21767 init_comm.go:68] [console] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
I0526 14:41:15.228737   21767 init_comm.go:68] [console] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
I0526 14:41:15.229257   21767 init_comm.go:68] [console] TCP: Hash tables configured (established 1024 bind 1024)
I0526 14:41:15.229753   21767 init_comm.go:68] [console] UDP hash table entries: 256 (order: 1, 8192 bytes)
I0526 14:41:15.230254   21767 init_comm.go:68] [console] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
I0526 14:41:15.230601   21767 init_comm.go:68] [console] NET: Registered protocol family 1
I0526 14:41:15.231074   21767 init_comm.go:68] [console] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
I0526 14:41:15.231521   21767 init_comm.go:68] [console] pci 0000:00:01.0: PIIX3: Enabling Passive Release
I0526 14:41:15.232006   21767 init_comm.go:68] [console] pci 0000:00:01.0: Activating ISA DMA hang workarounds
I0526 14:41:15.232496   21767 init_comm.go:68] [console] Trying to unpack rootfs image as initramfs...
I0526 14:41:15.263172   21767 init_comm.go:68] [console] Freeing initrd memory: 2136K (ffff880007dda000 - ffff880007ff0000)
I0526 14:41:15.263899   21767 init_comm.go:68] [console] futex hash table entries: 256 (order: 2, 16384 bytes)
I0526 14:41:15.264704   21767 init_comm.go:68] [console] SGI XFS with ACLs, security attributes, no debug enabled
I0526 14:41:15.265228   21767 init_comm.go:68] [console] 9p: Installing v9fs 9p2000 file system support
I0526 14:41:15.267243   21767 init_comm.go:68] [console] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
I0526 14:41:15.267519   21767 init_comm.go:68] [console] io scheduler noop registered
I0526 14:41:15.267857   21767 init_comm.go:68] [console] io scheduler cfq registered (default)
I0526 14:41:15.268317   21767 init_comm.go:68] [console] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
I0526 14:41:15.268838   21767 init_comm.go:68] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
I0526 14:41:15.269449   21767 init_comm.go:68] [console] Warning: Processor Platform Limit event detected, but not handled.
I0526 14:41:15.269906   21767 init_comm.go:68] [console] Consider compiling CPUfreq support into your kernel.
I0526 14:41:15.290067   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
I0526 14:41:15.290647   21767 init_comm.go:68] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
I0526 14:41:15.311005   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
I0526 14:41:15.311586   21767 init_comm.go:68] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
I0526 14:41:15.331660   21767 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
I0526 14:41:15.332233   21767 init_comm.go:68] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
I0526 14:41:15.333075   21767 init_comm.go:68] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
I0526 14:41:15.356643   21767 init_comm.go:68] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
I0526 14:41:15.381688   21767 init_comm.go:68] [console] brd: module loaded
I0526 14:41:15.381903   21767 init_comm.go:68] [console] loop: module loaded
I0526 14:41:15.402271   21767 init_comm.go:68] [console] scsi host0: Virtio SCSI HBA
I0526 14:41:15.418581   21767 init_comm.go:68] [console] rtc_cmos 00:00: RTC can wake from S4
I0526 14:41:15.419243   21767 init_comm.go:68] [console] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
I0526 14:41:15.419795   21767 init_comm.go:68] [console] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
I0526 14:41:15.420206   21767 init_comm.go:68] [console] NET: Registered protocol family 10
I0526 14:41:15.420648   21767 init_comm.go:68] [console] NET: Registered protocol family 17
I0526 14:41:15.420974   21767 init_comm.go:68] [console] 9pnet: Installing 9P2000 support
I0526 14:41:15.441464   21767 init_comm.go:68] [console] registered taskstats version 1
I0526 14:41:15.442312   21767 init_comm.go:68] [console] rtc_cmos 00:00: setting system clock to 2016-05-26 06:41:15 UTC (1464244875)
I0526 14:41:15.443547   21767 init_comm.go:68] [console] Freeing unused kernel memory: 860K (ffffffff8161f000 - ffffffff816f6000)
I0526 14:41:15.444064   21767 init_comm.go:68] [console] create directory /sys
I0526 14:41:15.444298   21767 init_comm.go:68] [console] create directory /sbin
I0526 14:41:15.444511   21767 init_comm.go:68] [console] create directory /proc
I0526 14:41:15.444706   21767 init_comm.go:68] [console] uptime 0.30 0.02
I0526 14:41:15.444796   21767 init_comm.go:68] [console] 
I0526 14:41:15.445078   21767 init_comm.go:68] [console] create directory /dev/pts
I0526 14:41:15.445408   21767 init_comm.go:68] [console] open hyper channel /dev/vport0p1
I0526 14:41:15.445637   21767 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1464244875, "microseconds": 445472}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel0"}}
I0526 14:41:15.445667   21767 qmp_handler.go:107] got event: VSERPORT_CHANGE
I0526 14:41:15.445685   21767 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
I0526 14:41:15.445734   21767 init_comm.go:68] [console] send ready message
I0526 14:41:15.445998   21767 init_comm.go:68] [console] hyper send type 8, len 0
I0526 14:41:15.446061   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.446077   21767 init_comm.go:110] data length is 8
I0526 14:41:15.446086   21767 init_comm.go:143] Get init ready message
I0526 14:41:15.446111   21767 init_comm.go:190] got cmd:1
I0526 14:41:15.446134   21767 init_comm.go:281] send command 1 to init, payload: '{"hostname":"d6a01446059e","containers":[],"shareDir":"share_dir"}'.
I0526 14:41:15.446152   21767 init_comm.go:294] write 74 to init, payload: 'J{"hostname":"d6a01446059e","containers":[],"shareDir":"share_dir"}'.
I0526 14:41:15.446257   21767 init_comm.go:299] message sent, set pong timer
I0526 14:41:15.446273   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 5(EVENT_INIT_CONNECTED)
I0526 14:41:15.446287   21767 vm_states.go:490] begin to wait vm commands
I0526 14:41:15.446313   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.446329   21767 vm.go:260] Get the response from VM, VM id is vm-DNlnLYiACB!
I0526 14:41:15.446487   21767 init_comm.go:68] [console] channel sh.hyper.channel.1, directory sh.hyper.channel.0
I0526 14:41:15.446550   21767 init_comm.go:68] [console] 
I0526 14:41:15.446821   21767 init_comm.go:68] [console] open hyper channel /dev/vport0p2
I0526 14:41:15.447403   21767 init_comm.go:68] [console] hyper_init_event hyper channel event 0x6165c0, ops 0x6163c0, fd 3
I0526 14:41:15.447727   21767 init_comm.go:68] [console] hyper_add_event add event fd 3, 0x6163c0
I0526 14:41:15.448174   21767 init_comm.go:68] [console] hyper_init_event hyper ttyfd event 0x616588, ops 0x616380, fd 4
I0526 14:41:15.448498   21767 init_comm.go:68] [console] hyper_add_event add event fd 4, 0x616380
I0526 14:41:15.448723   21767 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 14:41:15.449183   21767 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 14:41:15.449615   21767 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 14:41:15.449787   21767 init_comm.go:68] [console] hyper_event_read
I0526 14:41:15.450024   21767 init_comm.go:68] [console] already read 8 bytes data
I0526 14:41:15.450250   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.450306   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.450332   21767 init_comm.go:110] data length is 12
I0526 14:41:15.450341   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.450352   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.450364   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.450381   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.450401   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.450409   21767 init_comm.go:256] send 74, receive 8
I0526 14:41:15.450998   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.451016   21767 init_comm.go:110] data length is 12
I0526 14:41:15.451024   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.451035   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.451048   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.451063   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.451074   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.451082   21767 init_comm.go:256] send 74, receive 74
I0526 14:41:15.451122   21767 init_comm.go:68] [console] get length 74
I0526 14:41:15.451134   21767 init_comm.go:68] [console] read 66 bytes data, total data 74
I0526 14:41:15.451143   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.452336   21767 init_comm.go:68] [console] 0 0 0 1 0 0 0 4a 7b 22 68 6f 73 74 6e 61 6d 65 22 3a 22 64 36 61 30 31 34 34 36 30 35 39 65 22 2c 22 63 6f 6e 74 61 69 6e 65 72 73 22 3a 5b 5d 2c 22 73 68 61 72 65 44 69 72 22 3a 22 73 68 61 72 65 5f 64 69 72 22 7d 
I0526 14:41:15.452639   21767 init_comm.go:68] [console]  hyper_channel_handle, type 1, len 74
I0526 14:41:15.453309   21767 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"d6a01446059e","containers":[],"shareDir":"share_dir"}, len 66
I0526 14:41:15.454058   21767 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"d6a01446059e","containers":[],"shareDir":"share_dir"}, len 66
I0526 14:41:15.454304   21767 init_comm.go:68] [console] jsmn parse successed, n is 7
I0526 14:41:15.454559   21767 init_comm.go:68] [console] token 0, type is 1, size is 3
I0526 14:41:15.454818   21767 init_comm.go:68] [console] token 1, type is 3, size is 1
I0526 14:41:15.455072   21767 init_comm.go:68] [console] hostname is d6a01446059e
I0526 14:41:15.455321   21767 init_comm.go:68] [console] token 3, type is 3, size is 1
I0526 14:41:15.455525   21767 init_comm.go:68] [console] container count 0
I0526 14:41:15.455789   21767 init_comm.go:68] [console] token 5, type is 3, size is 1
I0526 14:41:15.456017   21767 init_comm.go:68] [console] share tag is share_dir
I0526 14:41:15.456245   21767 init_comm.go:68] [console] create directory /tmp
I0526 14:41:15.456503   21767 init_comm.go:68] [console] create directory /tmp/hyper
I0526 14:41:15.456765   21767 init_comm.go:68] [console] create directory /tmp/hyper/proc
I0526 14:41:15.457487   21767 init_comm.go:68] [console] random: busybox urandom read with 8 bits of entropy available
I0526 14:41:15.457947   21767 init_comm.go:68] [console] finish rescan
I0526 14:41:15.458322   21767 init_comm.go:68] [console] create directory /tmp/hyper/shared
I0526 14:41:15.459775   21767 init_comm.go:68] [console] pod init pid 325
I0526 14:41:15.460086   21767 init_comm.go:68] [console] hyper send type 8, len 0
I0526 14:41:15.460285   21767 init_comm.go:68] [console] uptime 0.31 0.02
I0526 14:41:15.460373   21767 init_comm.go:68] [console] 
I0526 14:41:15.460600   21767 init_comm.go:68] [console] hyper send type 9, len 0
I0526 14:41:15.460676   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.460690   21767 init_comm.go:110] data length is 8
I0526 14:41:15.460699   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.460713   21767 init_comm.go:190] got cmd:9
I0526 14:41:15.460726   21767 init_comm.go:209] ack got, clear pong timer
I0526 14:41:15.460744   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 31(COMMAND_ACK)
I0526 14:41:15.460757   21767 vm_states.go:500] [starting] got init ack to &{1 859533633536 <nil> [] 859531513408}
I0526 14:41:15.460859   21767 context.go:211] VM vm-DNlnLYiACB: state change from STARTING to 'RUNNING'
I0526 14:41:15.460873   21767 vm_states.go:516] pod start success 
I0526 14:41:15.460897   21767 vm.go:260] Get the response from VM, VM id is vm-DNlnLYiACB!
I0526 14:41:15.460919   21767 hyperpod.go:319] result: code 0 Start POD success
I0526 14:41:15.460932   21767 hyperpod.go:185] get exec path /home/darcy/gocode/src/github.com/hyperhq/runv/runv-containerd
I0526 14:41:15.460951   21767 init_comm.go:68] [console] pid 324 exit normally, status 0
I0526 14:41:15.461252   21767 init_comm.go:68] [console] can not find exec whose pid is 324
I0526 14:41:15.461469   21767 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0526 14:41:15.470628   21767 hyperpod.go:234] nsListener pid is 22771
I0526 14:41:15.470657   21767 supervisor.go:168] createHyperPod() returns
I0526 14:41:15.470667   21767 hyperpod.go:257] createContainer()
I0526 14:41:15.470677   21767 process.go:33] process setupIO: stdin /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stdin, stdout /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stdout, stderr /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stderr
I0526 14:41:15.470715   21767 process.go:59] process setupIO() success
I0526 14:41:15.470731   21767 hyperpod.go:283] createContainer()
I0526 14:41:15.470740   21767 hyperpod.go:289] createContainer() calls c.run(p)
I0526 14:41:15.470752   21767 supervisor.go:53] Supervisor.CreateContainer() return: c:&{d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b 0xc82006cd80 map[init:0xc820332ea0] 0xc820495d00} p:&{init /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stdin /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stdout /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b/init-stderr 0xc82006cdb0 -1 d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b-init 0xc820495f40 true 0xc820495f80 <nil>}
I0526 14:41:15.470789   21767 server.go:50] end Supervisor.CreateContainer(), build api Container
I0526 14:41:15.470801   21767 server.go:55] gRPC respond CreateContainer
I0526 14:41:15.471080   21767 container.go:64] save state id d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b, boundle /var/run/docker/libcontainerd/d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b
I0526 14:41:15.471188   21767 container.go:95] prepare hypervisor info
I0526 14:41:15.471231   21767 ocf-linux.go:21] env: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
I0526 14:41:15.471279   21767 ocf-linux.go:21] env: HOSTNAME=d6a01446059e
I0526 14:41:15.471309   21767 ocf-linux.go:21] env: TERM=xterm
I0526 14:41:15.474188   21767 container.go:311] Skip mount point "/proc" of type proc
I0526 14:41:15.474259   21767 container.go:311] Skip mount point "/dev" of type tmpfs
I0526 14:41:15.479320   21767 container.go:311] Skip mount point "/sys" of type sysfs
I0526 14:41:15.479390   21767 container.go:311] Skip mount point "/sys/fs/cgroup" of type cgroup
I0526 14:41:15.479443   21767 container.go:311] Skip mount point "/dev/mqueue" of type mqueue
I0526 14:41:15.499909   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 34(GENERIC_OPERATION)
I0526 14:41:15.500004   21767 vm_states.go:303] handle GenericOperation(Attach) on state(RUNNING)
I0526 14:41:15.500037   21767 context.go:179] can not found container d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b
I0526 14:41:15.500070   21767 vm_states.go:220] attachment d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b-init is pending
I0526 14:41:15.573625   21767 hyperpod.go:127] interface configuration of pod ns is []
I0526 14:41:15.573671   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 34(GENERIC_OPERATION)
I0526 14:41:15.573685   21767 vm_states.go:303] handle GenericOperation(AddRoute) on state(RUNNING)
I0526 14:41:15.573702   21767 init_comm.go:190] got cmd:21
I0526 14:41:15.573719   21767 init_comm.go:281] send command 21 to init, payload: '{}'.
I0526 14:41:15.573738   21767 init_comm.go:294] write 10 to init, payload: ' 
{}'.
I0526 14:41:15.573754   21767 init_comm.go:299] message sent, set pong timer
I0526 14:41:15.574104   21767 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 14:41:15.574533   21767 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 14:41:15.574971   21767 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 14:41:15.575139   21767 init_comm.go:68] [console] hyper_event_read
I0526 14:41:15.575379   21767 init_comm.go:68] [console] already read 8 bytes data
I0526 14:41:15.575615   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.575685   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.575705   21767 init_comm.go:110] data length is 12
I0526 14:41:15.575713   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.575725   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.575742   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.575765   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.575777   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.575785   21767 init_comm.go:256] send 10, receive 8
I0526 14:41:15.576382   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.576397   21767 init_comm.go:110] data length is 12
I0526 14:41:15.576405   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.576415   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.576417   21767 init_comm.go:68] [console] get length 10
I0526 14:41:15.576434   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.576451   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.576464   21767 init_comm.go:256] send 10, receive 10
I0526 14:41:15.576438   21767 init_comm.go:68] [console] read 2 bytes data, total data 10
I0526 14:41:15.576480   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.576427   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.576701   21767 init_comm.go:68] [console] 0 0 0 15 0 0 0 a 7b 7d 
I0526 14:41:15.577019   21767 init_comm.go:68] [console]  hyper_channel_handle, type 21, len 10
I0526 14:41:15.577226   21767 init_comm.go:68] [console] routes need array
I0526 14:41:15.577433   21767 init_comm.go:68] [console] fail to parse routes
I0526 14:41:15.577620   21767 init_comm.go:68] [console] parse route failed
I0526 14:41:15.577874   21767 init_comm.go:68] [console] hyper send type 10, len 0
I0526 14:41:15.577952   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.577967   21767 init_comm.go:110] data length is 8
I0526 14:41:15.577976   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.577989   21767 init_comm.go:190] got cmd:10
I0526 14:41:15.578004   21767 init_comm.go:209] ack got, clear pong timer
E0526 14:41:15.578016   21767 hyperpod.go:152] Error: 
E0526 14:41:15.578034   21767 container.go:145] fail to initialize pod network Error: 
I0526 14:41:15.578046   21767 supervisor.go:115] reap container d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b processId init
I0526 14:41:15.578070   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 24(COMMAND_SHUTDOWN)
I0526 14:41:15.578082   21767 vm_states.go:328] got shutdown command, shutting down
I0526 14:41:15.578097   21767 context.go:211] VM vm-DNlnLYiACB: state change from RUNNING to 'TERMINATING'
I0526 14:41:15.578108   21767 init_comm.go:190] got cmd:4
I0526 14:41:15.578122   21767 init_comm.go:281] send command 4 to init, payload: 'null'.
I0526 14:41:15.578139   21767 init_comm.go:294] write 12 to init, payload: ' 
                                                                            null'.
I0526 14:41:15.584221   21767 init_comm.go:299] message sent, set pong timer
I0526 14:41:15.580794   21767 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 14:41:15.584243   21767 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 14:41:15.586745   21767 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 14:41:15.586943   21767 init_comm.go:68] [console] hyper_event_read
I0526 14:41:15.587197   21767 init_comm.go:68] [console] already read 8 bytes data
I0526 14:41:15.587442   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.587530   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.587549   21767 init_comm.go:110] data length is 12
I0526 14:41:15.587557   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.587568   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.587584   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.587601   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.587612   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.587620   21767 init_comm.go:256] send 12, receive 8
I0526 14:41:15.587695   21767 init_comm.go:68] [console] get length 12
I0526 14:41:15.587980   21767 init_comm.go:68] [console] read 4 bytes data, total data 12
I0526 14:41:15.588225   21767 init_comm.go:68] [console] hyper send type 14, len 4
I0526 14:41:15.588284   21767 init_comm.go:106] read 8/8 [length = 0]
I0526 14:41:15.588297   21767 init_comm.go:110] data length is 12
I0526 14:41:15.588304   21767 init_comm.go:96] trying to read 4 bytes
I0526 14:41:15.588315   21767 init_comm.go:106] read 12/12 [length = 12]
I0526 14:41:15.588330   21767 init_comm.go:96] trying to read 8 bytes
I0526 14:41:15.588344   21767 init_comm.go:190] got cmd:14
I0526 14:41:15.588354   21767 init_comm.go:253] get command NEXT
I0526 14:41:15.588363   21767 init_comm.go:256] send 12, receive 12
I0526 14:41:15.588544   21767 init_comm.go:68] [console] 0 0 0 4 0 0 0 c 6e 75 6c 6c 
I0526 14:41:15.588829   21767 init_comm.go:68] [console]  hyper_channel_handle, type 4, len 12
I0526 14:41:15.589051   21767 init_comm.go:68] [console] get DESTROYPOD message
I0526 14:41:15.589520   21767 init_comm.go:68] [console] Sending SIGTERM
I0526 14:41:15.589689   21767 init_comm.go:68] [console] kill process 325
I0526 14:41:15.589883   21767 init_comm.go:68] [console] kill process 323
I0526 14:41:15.590053   21767 init_comm.go:68] [console] kill process 322
I0526 14:41:15.590215   21767 init_comm.go:68] [console] kill process 65
I0526 14:41:15.590400   21767 init_comm.go:68] [console] kill process 64
I0526 14:41:15.590565   21767 init_comm.go:68] [console] kill process 63
I0526 14:41:15.590732   21767 init_comm.go:68] [console] kill process 62
I0526 14:41:15.590903   21767 init_comm.go:68] [console] kill process 61
I0526 14:41:15.591078   21767 init_comm.go:68] [console] kill process 60
I0526 14:41:15.591237   21767 init_comm.go:68] [console] kill process 59
I0526 14:41:15.591430   21767 init_comm.go:68] [console] kill process 58
I0526 14:41:15.591597   21767 init_comm.go:68] [console] kill process 57
I0526 14:41:15.591761   21767 init_comm.go:68] [console] kill process 56
I0526 14:41:15.591950   21767 init_comm.go:68] [console] kill process 55
I0526 14:41:15.592115   21767 init_comm.go:68] [console] kill process 54
I0526 14:41:15.592281   21767 init_comm.go:68] [console] kill process 53
I0526 14:41:15.592444   21767 init_comm.go:68] [console] kill process 52
I0526 14:41:15.592621   21767 init_comm.go:68] [console] kill process 51
I0526 14:41:15.592787   21767 init_comm.go:68] [console] kill process 50
I0526 14:41:15.592974   21767 init_comm.go:68] [console] kill process 49
I0526 14:41:15.593138   21767 init_comm.go:68] [console] kill process 48
I0526 14:41:15.593303   21767 init_comm.go:68] [console] kill process 47
I0526 14:41:15.593480   21767 init_comm.go:68] [console] kill process 37
I0526 14:41:15.593646   21767 init_comm.go:68] [console] kill process 23
I0526 14:41:15.593823   21767 init_comm.go:68] [console] kill process 22
I0526 14:41:15.593998   21767 init_comm.go:68] [console] kill process 21
I0526 14:41:15.594165   21767 init_comm.go:68] [console] kill process 20
I0526 14:41:15.594324   21767 init_comm.go:68] [console] kill process 19
I0526 14:41:15.594489   21767 init_comm.go:68] [console] kill process 18
I0526 14:41:15.594674   21767 init_comm.go:68] [console] kill process 17
I0526 14:41:15.594848   21767 init_comm.go:68] [console] kill process 16
I0526 14:41:15.595014   21767 init_comm.go:68] [console] kill process 15
I0526 14:41:15.595175   21767 init_comm.go:68] [console] kill process 14
I0526 14:41:15.595362   21767 init_comm.go:68] [console] kill process 13
I0526 14:41:15.595542   21767 init_comm.go:68] [console] kill process 12
I0526 14:41:15.595697   21767 init_comm.go:68] [console] kill process 11
I0526 14:41:15.595884   21767 init_comm.go:68] [console] kill process 10
I0526 14:41:15.596044   21767 init_comm.go:68] [console] kill process 9
I0526 14:41:15.596205   21767 init_comm.go:68] [console] kill process 8
I0526 14:41:15.596363   21767 init_comm.go:68] [console] kill process 7
I0526 14:41:15.596522   21767 init_comm.go:68] [console] kill process 6
I0526 14:41:15.596697   21767 init_comm.go:68] [console] kill process 5
I0526 14:41:15.596870   21767 init_comm.go:68] [console] kill process 4
I0526 14:41:15.597032   21767 init_comm.go:68] [console] kill process 3
I0526 14:41:15.597187   21767 init_comm.go:68] [console] kill process 2
I0526 14:41:16.267414   21767 init_comm.go:68] [console] tsc: Refined TSC clocksource calibration: 3092.974 MHz
I0526 14:41:16.268277   21767 init_comm.go:68] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2c955ac38be, max_idle_ns: 440795348546 ns
I0526 14:41:16.445769   21767 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1464244875, "microseconds": 446884}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel1"}}
I0526 14:41:16.445810   21767 qmp_handler.go:107] got event: VSERPORT_CHANGE
I0526 14:41:16.445833   21767 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
I0526 14:41:25.578208   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 3(EVENT_VM_TIMEOUT)
W0526 14:41:25.578256   21767 vm_states.go:651] VM did not exit in time, try to stop it
E0526 14:41:25.578273   21767 vm_states.go:294] Shutting down because of an exception: vm terminating timeout
I0526 14:41:25.578293   21767 qmp_handler.go:296] got new session
I0526 14:41:25.578314   21767 qmp_handler.go:225] Begin process command session
I0526 14:41:25.578338   21767 qmp_handler.go:243] sending command (1) {"execute":"quit"}
I0526 14:41:25.578374   21767 vm.go:298] Got response: 7: vm terminating timeout
I0526 14:41:25.578770   21767 qmp_handler.go:103] got a message {"return": {}}
I0526 14:41:25.578839   21767 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1464244885, "microseconds": 578746}, "event": "SHUTDOWN"}
I0526 14:41:25.578865   21767 qmp_handler.go:107] got event: SHUTDOWN
I0526 14:41:25.578875   21767 qmp_handler.go:152] Shutdown, quit QMP receiver
I0526 14:41:25.578886   21767 qmp_handler.go:323] got QMP event SHUTDOWN
I0526 14:41:25.578895   21767 qmp_handler.go:325] got QMP shutdown event, quit...
I0526 14:41:25.578904   21767 hypervisor.go:29] vm vm-DNlnLYiACB: main event loop got message 1(EVENT_VM_EXIT)
I0526 14:41:25.578915   21767 vm_states.go:623] Got VM shutdown event while terminating, go to cleaning up
I0526 14:41:25.578929   21767 vm_states.go:36] VM has exit...
I0526 14:41:25.578941   21767 devicemap.go:93] All resource being released, someone is waiting for us...
I0526 14:41:25.578949   21767 context.go:198] no more device to release/remove/umount, quit
I0526 14:41:25.578959   21767 tty.go:233] Close tty d6a01446059ea660f3281ff4ceba4d307e9dc8c469185e74b34157129cb3bc2b-init
I0526 14:41:25.579018   21767 qemu_process.go:19] quit watch dog.
I0526 14:41:25.579046   21767 vm.go:298] Got response: 2: VM shut down
I0526 14:41:25.579060   21767 hyperpod.go:342] StopPod fail: QEMU response data is nil
E0526 14:41:25.583432   21767 tty.go:90] read tty data failed
I0526 14:41:25.583457   21767 tty.go:151] tty socket closed, quit the reading goroutine EOF
I0526 14:41:25.583488   21767 tty.go:118] tty chan closed, quit sent goroutine
E0526 14:41:25.583500   21767 init_comm.go:99] read init data failed
I0526 14:41:25.583432   21767 tty.go:428] Input byte chan closed, close the output string chan
I0526 14:41:25.583617   21767 init_comm.go:70] console output end
I0526 14:41:45.578123   21767 init_comm.go:216] Send ping message to init
I0526 14:41:45.578197   21767 init_comm.go:190] got cmd:12
I0526 14:41:45.578216   21767 init_comm.go:281] send command 12 to init, payload: 'null'.
I0526 14:41:45.578254   21767 init_comm.go:294] write 0 to init, payload: '

                                                                           null'.

enlarge stdin buffer in hypervisor/tty.go

Support other guest OSs that run VirtualBox

Eg. Windows and FreeBSD.

move fd preparation code from hypervisor/network/*.go to hypervisor/qemu/

it is qemu specific code

remove Fd from HostNicInfo
remove Fd from InterfaceCreated
remove File from Settings

go version needed

In the build section, may want to specify minimum go version needed.
I have tried compilation using go version 1.2 and 1.4, and got error from both of them.
Once I upgraded go to 1.5.1, then I was able to compile runv.

runv-containerd: fix route

the default route is missing.

speed up cpu hotplug on non-kvm host

it is important to test cache functionality on travis

cli(oci container): bind mount volume by guest

so that the container process can see the mount point and get some information of the volume(size, ...etc).
and it makes df show more information and make other tools based on mount point works. (backup tools?).

Unikernel support

As I mentioned on the opencontainer list I am interested in supporting unikernels in VMs with opencontainers. There is a big overlap with runv here, so I am wondering whether to merge into runv or to fork.

The main differences are:

the application is the executed kernel, not a different kernel + initrd
the pod concept doesnt work as you can only execute one application per vm
create container, run hook, run application makes less sense as you just create and run (post hook?).
will need to add PV Xen, as lots of unikernels currently only support that.

I don't yet have a sense of how intrusive these changes will be (particularly around the pod control part), so I guess I will just start experimenting; worst case we should be able to share much of the VM control code I suppose.

Tracking issue for handling OCI version 1.0.0-rc2

Handle any updates required to support OCI runtime specification 1.0.0-rc2:

https://github.com/opencontainers/runtime-spec/releases/tag/v1.0.0-rc2

runv-containerd hangs

Start runv-containerd and connect it with docker daemon, then execute:

# cid=$(docker run -tid busybox sh) && docker exec -ti $cid echo hello

docker daemon hangs.

After some investigation, I found that at the time when it ran "docker exec", the container is actually not started/ready yet.

I can throw an error out but that doesn't solve it. Could you fix it?

init_comm: should we reply all commands in queue when got INIT_FINISHPOD messsage?

here: https://github.com/hyperhq/runv/blob/master/hypervisor/init_comm.go#L263

Image such a case:

Client initiate a Kill command to the last container, which will lead to the container exit and pod finish.
Before the container is killed (before INIT_FINISHPOD was received by runV), Client initiate a second kill command.
Before the second command was replied by hyperstart, the init_comm got INIT_FINISHPOD

Then the second kill command will never got replied.

yum isn't working inside vm

I'm trying docker + runv-containerd + runv with stock kernel/initrd from hyperstart project.
After I run:
docker run -it --rm centos:6 /bin/bash

Inside the vm:

[root@4a2b5ba9b6ef /]# yum
rpmdb: mmap: Invalid argument
error: db3 error(22) from dbenv->open: Invalid argument
error: cannot open Packages index using db3 - Invalid argument (22)
error: cannot open Packages database in /var/lib/rpm
CRITICAL:yum.main:

Error: rpmdb open failed

Godep can't restore libvirt, commit 057f70a36a6b5d4ea19be345c2369e27dd022e01 doesnt exit

https://github.com/hyperhq/runv/blob/master/Godeps/Godeps.json#L11-L13

Godep can't restore libvirt, because this commit 057f70a36a6b5d4ea19be345c2369e27dd022e01 doesnt exist at all.

Can you check it?

Networking for runv VMs

Is there any documentation which describes how to setup networking for runv VMs?

unsettled things about #206

the case that multi container shares namespace is untested
if we start a container and exec in it and then exit the exec, the runv cmd of runv start will get error when it exits.
c.Events error: rpc error: code = 2 desc = grpc: the client connection is closing
other test....

split the StartPod event into small operations

Add support for HyperKit

For Mac Docker has created HyperKit based on the OS X Hypervisor Framework.
This is could be a great lightweight hypervisor to use in runc on Macs

No explicit license for this repo present

Can't handle very long input command lines

I've been playing with a (somewhat unholy) mixing of runv and drone CI. This looks like it should work out of the box, but the initial container startup on one of my attempts fails with "too long" - I'm guessing because the .drone.yml is serialized as a very large single line of JSON passed to the init, which chokes on it.

Error log:

I0907 12:10:59.002003     878 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0907 12:10:59.002798     878 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61d620, fd 3. ops 0x61d400
I0907 12:10:59.003572     878 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61d620, fd 3, 0x61d400
I0907 12:10:59.003849     878 init_comm.go:68] [console] hyper_event_read
I0907 12:10:59.004237     878 init_comm.go:68] [console] already read 8 bytes data
I0907 12:10:59.004609     878 init_comm.go:68] [console] hyper send type 14, len 4
I0907 12:10:59.004695     878 init_comm.go:106] read 8/8 [length = 0]
I0907 12:10:59.004705     878 init_comm.go:110] data length is 12
I0907 12:10:59.004713     878 init_comm.go:96] trying to read 4 bytes
I0907 12:10:59.004724     878 init_comm.go:106] read 12/12 [length = 12]
I0907 12:10:59.004747     878 init_comm.go:96] trying to read 8 bytes
I0907 12:10:59.004765     878 init_comm.go:225] got cmd:14
I0907 12:10:59.004777     878 init_comm.go:288] get command NEXT
I0907 12:10:59.004788     878 init_comm.go:291] send 512, receive 8
I0907 12:10:59.004910     878 init_comm.go:68] [console] get length 15890
I0907 12:10:59.005325     878 init_comm.go:68] [console] get length 15890, too long
I0907 12:10:59.006646     878 init_comm.go:68] [console] Kernel panic - not syncing: Attempted to kill init! exitcode=0x00000000
I0907 12:10:59.006670     878 init_comm.go:68] [console] 
I0907 12:10:59.007172     878 init_comm.go:68] [console] CPU: 0 PID: 1 Comm: init Not tainted 4.4.12-hyper #1
I0907 12:10:59.008271     878 init_comm.go:68] [console] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
I0907 12:10:59.009332     878 init_comm.go:68] [console]  0000000000000000 ffffffff8125831c ffffffff81572af0 ffff88000749feb8
I0907 12:10:59.010006     878 init_comm.go:68] [console]  ffffffff810c5bca 0000000000000010 ffff88000749fec8 ffff88000749fe68
I0907 12:10:59.010688     878 init_comm.go:68] [console]  ffffffff810c338f 0000000000000000 ffff880007492c10 0000000000000000
I0907 12:10:59.010894     878 init_comm.go:68] [console] Call Trace:
I0907 12:10:59.011312     878 init_comm.go:68] [console]  [<ffffffff8125831c>] ? dump_stack+0x5c/0x80
I0907 12:10:59.011696     878 init_comm.go:68] [console]  [<ffffffff810c5bca>] ? panic+0xc3/0x1e0
I0907 12:10:59.012518     878 init_comm.go:68] [console]  [<ffffffff810c338f>] ? perf_event_exit_task+0x9f/0x350
I0907 12:10:59.013181     878 init_comm.go:68] [console]  [<ffffffff8104e408>] ? do_exit+0xa68/0xa70
I0907 12:10:59.013667     878 init_comm.go:68] [console]  [<ffffffff8103f4d8>] ? __do_page_fault+0x168/0x3b0
I0907 12:10:59.014369     878 init_comm.go:68] [console]  [<ffffffff8104e474>] ? do_group_exit+0x34/0xa0
I0907 12:10:59.015123     878 init_comm.go:68] [console]  [<ffffffff8104e4eb>] ? SyS_exit_group+0xb/0x10
I0907 12:10:59.016052     878 init_comm.go:68] [console]  [<ffffffff8148a3ee>] ? entry_SYSCALL_64_fastpath+0x12/0x71
I0907 12:10:59.016532     878 init_comm.go:68] [console] Kernel Offset: disabled

Replace github.com/codegangsta/cli by github.com/urfave/cli

The package got moved, please update Godeps and relevant source files.

runv-containerd panics under pressure test

runv-containerd panics after started 3000 containers.

panic logs:

panic: send on closed channel

goroutine 1866548 [running]:
panic(0x9376c0, 0xc9f6e4fcd0)
    /usr/local/go/src/runtime/panic.go:481 +0x3e6
github.com/hyperhq/runv/hypervisor.waitInitAck(0xc85bb7cd80, 0xc8c2050040)
    /home/darcy/gocode/src/github.com/hyperhq/runv/hypervisor/init_comm.go:325 +0x25e
created by github.com/hyperhq/runv/hypervisor.waitCmdToInit
    /home/darcy/gocode/src/github.com/hyperhq/runv/hypervisor/init_comm.go:179 +0x103

bug report: stdin/stdout hangs when call runv-containerd

When I try to call runv-containerd with docker, if I don't specify terminal(-t), it hangs.

Normal case with -t:

$ docker run -ti --net none busybox ls
bin   dev   etc   home  proc  root  sys   tmp   usr   var
$

it hangs if without -t:

$ docker run -i --net none busybox ls
bin
dev
etc
home
proc
root
sys
tmp
usr
var

<hangs...Ctrl-C, Ctrl-D don't help>

Runv does not run on powerpc as it can not find exec whose seq is 1 from hyper_win_size.

Below is the log:

hyper_handle_event get event 16, de 0x100311dc338, fd 11. ops 0x10025950^M
hyper_handle_event event EPOLLHUP, de 0x100311dc338, fd 11, 0x10025950^M
stdin_hup^M
pts_hup, seq 1^M
last user of exec exit, release^M
hyper_modify_event modify event fd 4, 0x10025d88, event 5^M
hyper_release_exec exit code 255^M
hyper_release_exec container init exited, type 17, remains 1, policy 0^M
hyper send type 13, len 4^M
fopen /proc/324/status^M
find sigign 0000000000000000^M
mask is 0^M
open /tmp/hyper/resolv.conf failed: No such file or directory^M
hyper_loop epoll_wait 1^M
hyper_handle_event get event 4, de 0x10025d88, fd 4. ops 0x10025920^M
hyper_handle_event event EPOLLOUT, de 0x10025d88, fd 4, 0x10025920^M
hyper_modify_event modify event fd 4, 0x10025d88, event 1^M
hyper_loop epoll_wait 1^M
hyper_handle_event get event 1, de 0x10025dc0, fd 3. ops 0x100258f0^M
hyper_handle_event event EPOLLIN, de 0x10025dc0, fd 3, 0x100258f0^M
hyper_event_read^M
already read 8 bytes data^M
hyper send type 14, len 4^M
get length 39^M
read 31 bytes data, total data 39^M
hyper send type 14, len 4^M
0 0 0 b 0 0 0 27 7b 22 63 6f 6c 75 6d 6e 22 3a 31 36 39 2c 22 72 6f 77 22 3a 34 37 2c 22 73 65 71 22 3a 31 7d ^M
hyper_channel_handle, type 11, len 39^M
call hyper_win_size, json {"column":169,"row":47,"seq":1}41df0708ae52382d350a8d9a936ac2d22ff6e16f","rootfs":"rootfs","image":"8d71e3380bd5b357a77f4c9c41df0708ae52382d350a8d9a936ac2d22ff6e16f","process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"env":"TERM","value":"xterm"}],"workdir":"/"},"restartPolicy":"never","initialize":false}, len 31^M
can not find exec whose seq is 1^M
hyper send type 9, len 0^M
hyper_loop epoll_wait 1^M
hyper_handle_event get event 1, de 0x10025dc0, fd 3. ops 0x100258f0^M
hyper_handle_event event EPOLLIN, de 0x10025dc0, fd 3, 0x100258f0^M
hyper_event_read^M
already read 8 bytes data^M
hyper send type 14, len 4^M
get length 8^M
0 0 0 4 0 0 0 8 ^M
hyper_channel_handle, type 4, len 8^M
get DESTROYPOD message^M
hyper send type 9, len 0^M
reboot: Power down^M
RTAS power-off r

Any idea??

Problem running runv on Ubuntu 14.04

Hi, I am trying to run runv on Ubuntu 14.04,but it just failed.
I run the flowing commands:


mkdir /mycontainer
cd /mycontainer
mkdir rootfs
docker export $(docker create busybox) | tar -C rootfs -xvf -
runv spec
#kernel and hyper-initrd.img are moved from hyperstart/build
runv --debug --kernel kernel --initrd hyper-initrd.img --driver=qemu start -b /mycontainer/ test

And I get the following warnings(the container ended without execution)


error rpc error: code = 11 desc = EOF

Some logs from runv-namespaced.INFO:


I0717 11:01:44.010278    7328 init_comm.go:68] [console] enter hyper_loop
I0717 11:01:44.010947    7328 init_comm.go:68] [console] hyper_init_event hyper channel event 0x615580, ops 0x6153a0, fd 3
I0717 11:01:44.011421    7328 init_comm.go:68] [console] hyper_add_event add event fd 3, 0x6153a0
I0717 11:01:44.012050    7328 init_comm.go:68] [console] hyper_init_event hyper ttyfd event 0x615548, ops 0x615360, fd 4
I0717 11:01:44.012555    7328 init_comm.go:68] [console] hyper_add_event add event fd 4, 0x615360
I0717 11:01:44.012864    7328 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0717 11:01:44.013502    7328 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x615580, fd 3. ops 0x6153a0
I0717 11:01:44.014100    7328 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x615580, fd 3, 0x6153a0
I0717 11:01:44.014362    7328 init_comm.go:68] [console] hyper_event_read
I0717 11:01:44.014682    7328 init_comm.go:68] [console] already read 8 bytes data
I0717 11:01:44.015007    7328 init_comm.go:68] [console] hyper send type 14, len 4
I0717 11:01:44.015092    7328 init_comm.go:106] read 8/8 [length = 0]
I0717 11:01:44.015102    7328 init_comm.go:110] data length is 12
I0717 11:01:44.015108    7328 init_comm.go:96] trying to read 4 bytes
I0717 11:01:44.015119    7328 init_comm.go:106] read 12/12 [length = 12]
I0717 11:01:44.015129    7328 init_comm.go:96] trying to read 8 bytes
I0717 11:01:44.015159    7328 init_comm.go:190] got cmd:14
I0717 11:01:44.015165    7328 init_comm.go:253] get command NEXT
I0717 11:01:44.015169    7328 init_comm.go:256] send 67, receive 8
I0717 11:01:44.015268    7328 init_comm.go:68] [console] get length 67
I0717 11:01:44.015666    7328 init_comm.go:68] [console] read 59 bytes data, total data 67
I0717 11:01:44.016037    7328 init_comm.go:68] [console] hyper send type 14, len 4
I0717 11:01:44.016117    7328 init_comm.go:106] read 8/8 [length = 0]
I0717 11:01:44.016124    7328 init_comm.go:110] data length is 12
I0717 11:01:44.016127    7328 init_comm.go:96] trying to read 4 bytes
I0717 11:01:44.016133    7328 init_comm.go:106] read 12/12 [length = 12]
I0717 11:01:44.016141    7328 init_comm.go:96] trying to read 8 bytes
I0717 11:01:44.016155    7328 init_comm.go:190] got cmd:14
I0717 11:01:44.016163    7328 init_comm.go:253] get command NEXT
I0717 11:01:44.016168    7328 init_comm.go:256] send 67, receive 67
I0717 11:01:44.017801    7328 init_comm.go:68] [console] 0 0 0 1 0 0 0 43 7b 22 68 6f 73 74 6e 61 6d 65 22 3a 22 73 68 65 6c 6c 22 2c 22 63 6f 6e 74 61 69 6e 65 72 73 22 3a 5b 5d 2c 22 73 68 61 72 65 44 69 72 22 3a 22 73 68 61 72 65 5f 64 69 72 22 7d 
I0717 11:01:44.018226    7328 init_comm.go:68] [console]  hyper_channel_handle, type 1, len 67
I0717 11:01:44.019103    7328 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"shell","containers":[],"shareDir":"share_dir"}., len 59
I0717 11:01:44.020202    7328 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"shell","containers":[],"shareDir":"share_dir"}., len 59
I0717 11:01:44.020549    7328 init_comm.go:68] [console] jsmn parse successed, n is 7
I0717 11:01:44.020892    7328 init_comm.go:68] [console] token 0, type is 1, size is 3
I0717 11:01:44.021249    7328 init_comm.go:68] [console] token 1, type is 3, size is 1
I0717 11:01:44.021520    7328 init_comm.go:68] [console] hostname is shell
I0717 11:01:44.021863    7328 init_comm.go:68] [console] token 3, type is 3, size is 1
I0717 11:01:44.022129    7328 init_comm.go:68] [console] container count 0
I0717 11:01:44.023074    7328 init_comm.go:68] [console] random: busybox urandom read with 8 bits of entropy available
I0717 11:01:44.023446    7328 init_comm.go:68] [console] token 5, type is 3, size is 1
I0717 11:01:44.023739    7328 init_comm.go:68] [console] share tag is share_dir
I0717 11:01:44.024040    7328 init_comm.go:68] [console] create directory /tmp
I0717 11:01:44.024396    7328 init_comm.go:68] [console] create directory /tmp/hyper
I0717 11:01:44.024892    7328 init_comm.go:68] [console] create directory /tmp/hyper/proc
I0717 11:01:44.025383    7328 init_comm.go:68] [console] finish rescan
I0717 11:01:44.025902    7328 init_comm.go:68] [console] create directory /tmp/hyper/shared
I0717 11:01:44.026706    7328 init_comm.go:68] [console] pod init pid 325
I0717 11:01:44.027073    7328 init_comm.go:68] [console] hyper send type 8, len 0
I0717 11:01:44.027397    7328 init_comm.go:68] [console] in hyper_start_containers
I0717 11:01:44.027712    7328 init_comm.go:68] [console] out hyper_start_containers
I0717 11:01:44.027953    7328 init_comm.go:68] [console] uptime 0.34 0.02
I0717 11:01:44.028062    7328 init_comm.go:68] [console] 
I0717 11:01:44.028492    7328 init_comm.go:68] [console] hyper_channel_handle: STARTPOD finished
I0717 11:01:44.028838    7328 init_comm.go:68] [console] hyper send type 9, len 0
I0717 11:01:44.028919    7328 init_comm.go:106] read 8/8 [length = 0]
I0717 11:01:44.028926    7328 init_comm.go:110] data length is 8
I0717 11:01:44.028935    7328 init_comm.go:96] trying to read 8 bytes
I0717 11:01:44.028957    7328 init_comm.go:190] got cmd:9
I0717 11:01:44.028966    7328 init_comm.go:209] ack got, clear pong timer
I0717 11:01:44.028981    7328 hypervisor.go:29] vm vm-OewSSuQoQx: main event loop got message 31(COMMAND_ACK)
I0717 11:01:44.028988    7328 vm_states.go:499] [starting] got init ack to &{1 859531633408  [] 859533394400}
I0717 11:01:44.029241    7328 init_comm.go:68] [console] sigchld in hyper_init_sigchld
I0717 11:01:44.029498    7328 context.go:211] VM vm-OewSSuQoQx: state change from STARTING to 'RUNNING'
I0717 11:01:44.029507    7328 vm_states.go:515] pod start success 
I0717 11:01:44.029520    7328 vm.go:260] Get the response from VM, VM id is vm-OewSSuQoQx!
I0717 11:01:44.029535    7328 hyperpod.go:296] result: code 0 Start POD success
I0717 11:01:44.029541    7328 hyperpod.go:162] get exec path /usr/local/bin/runv
I0717 11:01:44.030054    7328 init_comm.go:68] [console] pid 324 exit normally, status 0
I0717 11:01:44.030090    7328 init_comm.go:68] [console] can not find exec whose pid is 324
I0717 11:01:44.030242    7328 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0717 11:01:44.030536    7328 init_comm.go:68] [console] epoll: n=-1 errno==EINTR
I0717 11:01:44.030862    7328 init_comm.go:68] [console] pod init enter infinite loop
I0717 11:01:44.048861    7328 hypervisor.go:29] vm vm-OewSSuQoQx: main event loop got message 24(COMMAND_SHUTDOWN)
I0717 11:01:44.048873    7328 vm_states.go:327] got shutdown command, shutting down
I0717 11:01:44.048887    7328 context.go:211] VM vm-OewSSuQoQx: state change from RUNNING to 'TERMINATING'
I0717 11:01:44.048900    7328 init_comm.go:190] got cmd:4
I0717 11:01:44.048911    7328 init_comm.go:281] send command 4 to init, payload: 'null'.
I0717 11:01:44.048928    7328 init_comm.go:294] write 12 to init, payload: '\00\00\00�\00\00\00null'.
I0717 11:01:44.048936    7328 init_comm.go:299] message sent, set pong timer
I0717 11:01:44.049362    7328 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0717 11:01:44.049907    7328 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x615580, fd 3. ops 0x6153a0
I0717 11:01:44.050442    7328 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x615580, fd 3, 0x6153a0
I0717 11:01:44.050648    7328 init_comm.go:68] [console] hyper_event_read
I0717 11:01:44.050940    7328 init_comm.go:68] [console] already read 8 bytes data
I0717 11:01:44.051227    7328 init_comm.go:68] [console] hyper send type 14, len 4
I0717 11:01:44.051319    7328 init_comm.go:106] read 8/8 [length = 0]
I0717 11:01:44.051339    7328 init_comm.go:110] data length is 12
I0717 11:01:44.051345    7328 init_comm.go:96] trying to read 4 bytes
I0717 11:01:44.051355    7328 init_comm.go:106] read 12/12 [length = 12]
I0717 11:01:44.051378    7328 init_comm.go:96] trying to read 8 bytes
I0717 11:01:44.051389    7328 init_comm.go:190] got cmd:14
I0717 11:01:44.051393    7328 init_comm.go:253] get command NEXT
I0717 11:01:44.051397    7328 init_comm.go:256] send 12, receive 8
I0717 11:01:44.051557    7328 init_comm.go:68] [console] get length 12
I0717 11:01:44.051886    7328 init_comm.go:68] [console] read 4 bytes data, total data 12
I0717 11:01:44.052176    7328 init_comm.go:68] [console] hyper send type 14, len 4
I0717 11:01:44.052248    7328 init_comm.go:106] read 8/8 [length = 0]
I0717 11:01:44.052256    7328 init_comm.go:110] data length is 12
I0717 11:01:44.052259    7328 init_comm.go:96] trying to read 4 bytes
I0717 11:01:44.052265    7328 init_comm.go:106] read 12/12 [length = 12]
I0717 11:01:44.052274    7328 init_comm.go:96] trying to read 8 bytes
I0717 11:01:44.052286    7328 init_comm.go:190] got cmd:14
I0717 11:01:44.052291    7328 init_comm.go:253] get command NEXT
I0717 11:01:44.052294    7328 init_comm.go:256] send 12, receive 12
I0717 11:01:44.052575    7328 init_comm.go:68] [console] 0 0 0 4 0 0 0 c 6e 75 6c 6c 
I0717 11:01:44.052945    7328 init_comm.go:68] [console]  hyper_channel_handle, type 4, len 12
I0717 11:01:44.053221    7328 init_comm.go:68] [console] get DESTROYPOD message
I0717 11:01:44.053675    7328 init_comm.go:68] [console] Sending SIGTERM
I0717 11:01:44.053893    7328 init_comm.go:68] [console] kill process 325
I0717 11:01:44.054118    7328 init_comm.go:68] [console] kill process 323
I0717 11:01:44.054346    7328 init_comm.go:68] [console] kill process 322
I0717 11:01:44.054546    7328 init_comm.go:68] [console] kill process 65
I0717 11:01:44.054749    7328 init_comm.go:68] [console] kill process 64
I0717 11:01:44.054951    7328 init_comm.go:68] [console] kill process 63
I0717 11:01:44.055169    7328 init_comm.go:68] [console] kill process 62
I0717 11:01:44.055371    7328 init_comm.go:68] [console] kill process 61
I0717 11:01:44.055581    7328 init_comm.go:68] [console] kill process 60
I0717 11:01:44.055850    7328 init_comm.go:68] [console] kill process 59
I0717 11:01:44.056061    7328 init_comm.go:68] [console] kill process 58
I0717 11:01:44.056277    7328 init_comm.go:68] [console] kill process 57
I0717 11:01:44.056478    7328 init_comm.go:68] [console] kill process 56
I0717 11:01:44.056693    7328 init_comm.go:68] [console] kill process 55
I0717 11:01:44.056894    7328 init_comm.go:68] [console] kill process 54
I0717 11:01:44.057104    7328 init_comm.go:68] [console] kill process 53
I0717 11:01:44.057316    7328 init_comm.go:68] [console] kill process 52
I0717 11:01:44.057522    7328 init_comm.go:68] [console] kill process 51
I0717 11:01:44.057722    7328 init_comm.go:68] [console] kill process 50
I0717 11:01:44.057929    7328 init_comm.go:68] [console] kill process 49
I0717 11:01:44.058130    7328 init_comm.go:68] [console] kill process 48
I0717 11:01:44.058339    7328 init_comm.go:68] [console] kill process 47
I0717 11:01:44.058542    7328 init_comm.go:68] [console] kill process 37
I0717 11:01:44.058747    7328 init_comm.go:68] [console] kill process 23
I0717 11:01:44.058950    7328 init_comm.go:68] [console] kill process 22
I0717 11:01:44.059169    7328 init_comm.go:68] [console] kill process 21
I0717 11:01:44.059376    7328 init_comm.go:68] [console] kill process 20
I0717 11:01:44.059584    7328 init_comm.go:68] [console] kill process 19
I0717 11:01:44.059789    7328 init_comm.go:68] [console] kill process 18
I0717 11:01:44.059995    7328 init_comm.go:68] [console] kill process 17
I0717 11:01:44.060207    7328 init_comm.go:68] [console] kill process 16
I0717 11:01:44.060410    7328 init_comm.go:68] [console] kill process 15
I0717 11:01:44.060626    7328 init_comm.go:68] [console] kill process 14
I0717 11:01:44.060811    7328 init_comm.go:68] [console] kill process 13
I0717 11:01:44.060992    7328 init_comm.go:68] [console] kill process 12
I0717 11:01:44.061185    7328 init_comm.go:68] [console] kill process 11
I0717 11:01:44.061367    7328 init_comm.go:68] [console] kill process 10
I0717 11:01:44.061549    7328 init_comm.go:68] [console] kill process 9
I0717 11:01:44.061730    7328 init_comm.go:68] [console] kill process 8
I0717 11:01:44.061905    7328 init_comm.go:68] [console] kill process 7
I0717 11:01:44.062083    7328 init_comm.go:68] [console] kill process 6
I0717 11:01:44.062271    7328 init_comm.go:68] [console] kill process 5
I0717 11:01:44.062453    7328 init_comm.go:68] [console] kill process 4
I0717 11:01:44.062634    7328 init_comm.go:68] [console] kill process 3
I0717 11:01:44.062814    7328 init_comm.go:68] [console] kill process 2
I0717 11:01:44.801100    7328 init_comm.go:68] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2f75b1eac7a, max_idle_ns: 440795210882 ns
I0717 11:01:54.049105    7328 hypervisor.go:29] vm vm-OewSSuQoQx: main event loop got message 3(EVENT_VM_TIMEOUT)
W0717 11:01:54.049131    7328 vm_states.go:650] VM did not exit in time, try to stop it
E0717 11:01:54.049366    7328 vm_states.go:293] Shutting down because of an exception: vm terminating timeout
I0717 11:01:54.049508    7328 qmp_handler.go:296] got new session
I0717 11:01:54.049537    7328 qmp_handler.go:225] Begin process command session
I0717 11:01:54.049560    7328 qmp_handler.go:243] sending command (1) {"execute":"quit"}
I0717 11:01:54.049594    7328 vm.go:298] Got response: 7: vm terminating timeout
I0717 11:01:54.050074    7328 qmp_handler.go:103] got a message {"return": {}}
I0717 11:01:54.050137    7328 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1468724514, "microseconds": 50001}, "event": "SHUTDOWN"}
I0717 11:01:54.050159    7328 qmp_handler.go:107] got event: SHUTDOWN
I0717 11:01:54.050168    7328 qmp_handler.go:152] Shutdown, quit QMP receiver
I0717 11:01:54.050186    7328 qmp_handler.go:323] got QMP event SHUTDOWN
I0717 11:01:54.050195    7328 qmp_handler.go:325] got QMP shutdown event, quit...
I0717 11:01:54.050208    7328 hypervisor.go:29] vm vm-OewSSuQoQx: main event loop got message 1(EVENT_VM_EXIT)
I0717 11:01:54.050216    7328 vm_states.go:622] Got VM shutdown event while terminating, go to cleaning up
I0717 11:01:54.050222    7328 vm_states.go:36] VM has exit...
I0717 11:01:54.050233    7328 devicemap.go:93] All resource being released, someone is waiting for us...
I0717 11:01:54.050237    7328 context.go:198] no more device to release/remove/umount, quit
I0717 11:01:54.050270    7328 qemu_process.go:19] quit watch dog.
I0717 11:01:54.050289    7328 vm.go:298] Got response: 2: VM shut down
I0717 11:01:54.050300    7328 hyperpod.go:319] StopPod fail: QEMU response data is nil
I0717 11:01:54.050306    7328 hyperpod.go:309] start ns listener fail: EOF
I0717 11:01:54.050314    7328 supervisor.go:168] createHyperPod() returns
E0717 11:01:54.055261    7328 init_comm.go:99] read init data failed
E0717 11:01:54.055272    7328 tty.go:90] read tty data failed
I0717 11:01:54.055290    7328 tty.go:151] tty socket closed, quit the reading goroutine EOF
I0717 11:01:54.055305    7328 tty.go:428] Input byte chan closed, close the output string chan
I0717 11:01:54.055324    7328 init_comm.go:70] console output end
I0717 11:01:54.055329    7328 tty.go:118] tty chan closed, quit sent goroutine
I0717 11:02:14.029117    7328 init_comm.go:216] Send ping message to init
I0717 11:02:14.029156    7328 init_comm.go:190] got cmd:12
I0717 11:02:14.029220    7328 init_comm.go:281] send command 12 to init, payload: 'null'.
I0717 11:02:14.029262    7328 init_comm.go:294] write 0 to init, payload: '\00\00\00\00\00\00null'.

From the log, I find something weird is that


I0717 11:01:44.029507    7328 vm_states.go:515] pod start success 
I0717 11:01:44.029520    7328 vm.go:260] Get the response from VM, VM id is vm-OewSSuQoQx!
I0717 11:01:44.029535    7328 hyperpod.go:296] result: code 0 Start POD success
I0717 11:01:44.029541    7328 hyperpod.go:162] get exec path /usr/local/bin/runv
I0717 11:01:44.030054    7328 init_comm.go:68] [console] pid 324 exit normally, status 0
I0717 11:01:44.030090    7328 init_comm.go:68] [console] can not find exec whose pid is 324
I0717 11:01:44.030242    7328 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0717 11:01:44.030536    7328 init_comm.go:68] [console] epoll: n=-1 errno==EINTR
I0717 11:01:44.030862    7328 init_comm.go:68] [console] pod init enter infinite loop
I0717 11:01:44.048861    7328 hypervisor.go:29] vm vm-OewSSuQoQx: main event loop got message 24(COMMAND_SHUTDOWN)

after getting the log info "pod start success",we also get the log info "main event loop got message 24(COMMAND_SHUTDOWN)"
I think maybe the problem is because of this SHUTDOWN COMMAND.
I have tried many efforts on running runv :(
Any ideas to fix this ?
Looking forward to any help!~

distinguish the output of stdout&stderr when !tty

[root@sbox ~]# hyper run busybox sh -c "echo stdout; echo stderr 1>&2" 2>/dev/null
stdout
stderr
[root@sbox ~]# docker run busybox sh -c "echo stdout; echo stderr 1>&2" 2>/dev/null
stdout

flush ctx.hyperstart's pending commands before pause

and disable ctx.vm when paused.

Integrate runV with Docker

Docker is going to modify the Engine to directly call a binary implementing the Open Containers Specification, such as runC, rather than relying on an execution driver calling an external library (libcontainer) to set the container runtime up [1].
runV being the hypervisor-based equivalent of runC, it should be able to integrate with Docker.

However, several aspects require attention to perform a successful integration:

Fit runV Pod model to Docker’s single container model;
Make runV networking compatible with Docker’s CNM model;
Properly configure virtual machines with OCI specifications;
Implement all Docker runtime operations.

Model: Pod (or group of containers)

runV is designed to not only run one app-centric container within a VM, but instead run groups of containers related together (Pod); leveraging the VM as the hard boundaries of that Pod. It helps to optimise the VM density by reducing the memory overhead of the guest kernel and the hypervisor process, and also makes it easy to share namespaces among containers.

There is a pattern for container based apps, which consists in tight coupled containers as a scheduling unit. This pattern is implemented by Kubernetes Pod, among others.

However, Pods are not in Docker’s current model, i.e. it is not possible to create a Pod with Docker/runC. To have the Pod concept in Docker’s model, runV will treat each VM as an element equivalent to the network namespace, i.e:

in containers’ world, a Pod could be created in a single network namespace
in hypervisors’ world, a Pod could be created in a single VM

Containers Networking

runV’s networking part is going to fit the libnetwork CNM model:

Network: Bridge or OVS or others
Endpoint: The address and route info
Sandbox: The virtual machine, instead of a network namespace

The endpoint will “join” the Sandbox (using the method endpoint.Join(sandbox)) after a VM boots, and before the container starts to run. This will be implemented using the pre-start hook present in the OCI specs. As a VM is different than a container, runV will provide a new libnetwork driver, as well as a specific net hook program to setup the network of the hypervisor.

Configure virtual machines with OCI specifications

Currently, runV can launch VMs according to OCI specs, equivalent to runC. It is not yet optimized, and runV shall introduce some extra configuration parameters.

VM Boot parameter customization

runV is based on hypervisor technology, thus it requires path to kernel and initrd files to run containers with Kvm/Xen hypervisors; and path to vbox-boot-iso file in VirtualBox hypervisor. We suggest to add these values to the runtime configuration, i.e:

{
    "kernel": "/var/lib/hyper/vmlinuz",
    "initrd": "/var/lib/hyper/hyper-initrd.gz"
}

Configure vCPU number

Hypervisors require the number of vCPUs to be set to run a container in a VM.
Although runV can get the number of vCPUs from Resources.CPU.Cpus, the original purpose of this value is to be used for CPU affinity, and usually represents all the CPUs of the host by default. As it is too expensive for runV to use all the CPUs to run a container, runV needs a dedicated vCPU configuration entry.

Block device as rootfs

runV can run with a host directory as rootfs, which relies on features of hypervisors, such as virtfs (9p) for Kvm/Xen, or vboxsf for VirtualBox. These features work but cannot provide performances comparable to a native filesystem. It is better for runV to run on a hypervisor volume (image).

It would be better if the rootfs is allowed to be configured through the mount entry in the runtime.json file. Mount supports block devices, directories, and pseudo filesystems (procfs, sysfs, ...); then, runV could setup a raw device, or a hypervisor disk image, as rootfs.

Configure volumes (disk image) formats in specs

For mounting disk images as volumes, such as qcow2, rbd, or vdi formats, it is better to define these formats in the configuration, i.e:

"data": {
    "type": "xfs",
    "source": "qcow2:/volumes/testing.qcow",
    "options": ["noatime","noexec"]
}

Support all Docker runtime Container operations

tty

runV will provide tty/terminal access, as runC does.

exec

For runC containers, runc exec can execute programs in runC containers through setns and the namespace path. However, runV containers are running as VMs, which means setns and namespace path are meaningless for runv exec. runv exec needs a specific channel to notify the VM to execute programs. runV currently setups the channels based on a serial port device of the VM. These channels should be stored in a container’s state, then multiple runv exec can use the same channel to access the same VM.

pause/unpause and migration

The pause/unpause and migration in runV will be implemented in the context of the hypervisor.

[1] Docker Roadmap

Todo: support timeout of hooks

https://github.com/opencontainers/runtime-spec/blob/master/config.md#example-4

runv-containerd can't get network configure from docker

docker run -tid busybox sh:

runv-containerd log:

I0526 17:46:15.539427   22828 server.go:31] gRPC handle CreateContainer
I0526 17:46:15.540419   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 21(COMMAND_RUN_POD)
I0526 17:46:15.540502   22828 vm_states.go:449] got spec, prepare devices
I0526 17:46:15.540536   22828 vm_states.go:67] initial vm spec: {
        "hostname": "68988a52009d",
        "containers": [],
        "shareDir": "share_dir"
    }
I0526 17:46:15.540568   22828 context.go:211] VM vm-pEwxFWdQnA: state change from INIT to 'STARTING'
I0526 17:46:15.540582   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 10(EVENT_DEV_SKIP)
I0526 17:46:15.540594   22828 vm_states.go:476] device ready, could run pod.
I0526 17:46:15.540475   22828 qemu_process.go:63] cmdline arguments: -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -cpu host -kernel /var/lib/hyper/kernel -initrd /var/lib/hyper/hyper-initrd.img -append console=ttyS0 panic=1 no_timer_check -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,driftfix=slew -no-reboot -display none -boot strict=on -m 128 -smp 1 -qmp unix:/var/run/hyper/vm-pEwxFWdQnA/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-pEwxFWdQnA/console.sock,server,nowait -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -chardev socket,id=charch0,path=/var/run/hyper/vm-pEwxFWdQnA/hyper.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0 -chardev socket,id=charch1,path=/var/run/hyper/vm-pEwxFWdQnA/tty.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1 -fsdev local,id=virtio9p,path=/var/run/hyper/vm-pEwxFWdQnA/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir
I0526 17:46:15.540345   22828 vm.go:179] hyperHandlePodEvent pod pod-cRZjBcrYMI, vm vm-pEwxFWdQnA
I0526 17:46:15.562283   22828 qemu_process.go:74] starting daemon with pid: 23570
I0526 17:46:15.580748   22828 init_comm.go:53] connected to /var/run/hyper/vm-pEwxFWdQnA/console.sock
I0526 17:46:15.580869   22828 init_comm.go:60] connected /var/run/hyper/vm-pEwxFWdQnA/console.sock as telnet mode.
I0526 17:46:15.580792   22828 tty.go:144] tty socket connected
I0526 17:46:15.580924   22828 tty.go:87] tty: trying to read 12 bytes
I0526 17:46:15.580833   22828 qmp_handler.go:167] connected to /var/run/hyper/vm-pEwxFWdQnA/qmp.sock
I0526 17:46:15.580948   22828 qmp_handler.go:177] begin qmp init...
I0526 17:46:15.580871   22828 init_comm.go:133] Wating for init messages...
I0526 17:46:15.580973   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:15.617682   22828 qmp_handler.go:186] got qmp welcome, now sending command qmp_capabilities
I0526 17:46:15.617736   22828 qmp_handler.go:201] waiting for response
I0526 17:46:15.628141   22828 qmp_handler.go:103] got a message {"return": {}}
I0526 17:46:15.628246   22828 qmp_handler.go:210] got for response
I0526 17:46:15.628284   22828 qmp_handler.go:213] QMP connection initialized
I0526 17:46:15.628340   22828 qmp_handler.go:346] QMP initialzed, go into main QMP loop
I0526 17:46:15.628385   22828 qmp_handler.go:137] Begin receive QMP message
I0526 17:46:17.171967   22828 init_comm.go:68] [console] Initializing cgroup subsys cpuset
I0526 17:46:17.172231   22828 init_comm.go:68] [console] Initializing cgroup subsys cpu
I0526 17:46:17.172564   22828 init_comm.go:68] [console] Initializing cgroup subsys cpuacct
I0526 17:46:17.173795   22828 init_comm.go:68] [console] Linux version 4.4.7-hyper+ (bergwolf@vmfarm) (gcc version 5.2.1 20151010 (Ubuntu 5.2.1-22ubuntu2) ) #10 SMP Wed May 4 17:03:36 CST 2016
I0526 17:46:17.174264   22828 init_comm.go:68] [console] Command line: console=ttyS0 panic=1 no_timer_check
I0526 17:46:17.174777   22828 init_comm.go:68] [console] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
I0526 17:46:17.175433   22828 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'
I0526 17:46:17.175949   22828 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'
I0526 17:46:17.176465   22828 init_comm.go:68] [console] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'
I0526 17:46:17.177292   22828 init_comm.go:68] [console] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
I0526 17:46:17.177704   22828 init_comm.go:68] [console] x86/fpu: Using 'eager' FPU context switches.
I0526 17:46:17.178061   22828 init_comm.go:68] [console] e820: BIOS-provided physical RAM map:
I0526 17:46:17.178634   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
I0526 17:46:17.179225   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
I0526 17:46:17.179822   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
I0526 17:46:17.180394   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffdfff] usable
I0526 17:46:17.180985   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000007ffe000-0x0000000007ffffff] reserved
I0526 17:46:17.181564   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
I0526 17:46:17.182151   22828 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
I0526 17:46:17.182523   22828 init_comm.go:68] [console] NX (Execute Disable) protection: active
I0526 17:46:17.182709   22828 init_comm.go:68] [console] SMBIOS 2.4 present.
I0526 17:46:17.182944   22828 init_comm.go:68] [console] Hypervisor detected: KVM
I0526 17:46:17.195427   22828 init_comm.go:68] [console] e820: last_pfn = 0x7ffe max_arch_pfn = 0x400000000
I0526 17:46:17.196012   22828 init_comm.go:68] [console] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- WT  
I0526 17:46:17.196738   22828 init_comm.go:68] [console] found SMP MP-table at [mem 0x000f64b0-0x000f64bf] mapped at [ffff8800000f64b0]
I0526 17:46:17.197084   22828 init_comm.go:68] [console] RAMDISK: [mem 0x07dda000-0x07feffff]
I0526 17:46:17.197540   22828 init_comm.go:68] [console] ACPI: Early table checksum verification disabled
I0526 17:46:17.198009   22828 init_comm.go:68] [console] ACPI: RSDP 0x00000000000F6330 000014 (v00 BOCHS )
I0526 17:46:17.198763   22828 init_comm.go:68] [console] ACPI: RSDT 0x0000000007FFF688 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
I0526 17:46:17.199524   22828 init_comm.go:68] [console] ACPI: FACP 0x0000000007FFEBDA 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
I0526 17:46:17.200282   22828 init_comm.go:68] [console] ACPI: DSDT 0x0000000007FFE040 000B9A (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
I0526 17:46:17.200622   22828 init_comm.go:68] [console] ACPI: FACS 0x0000000007FFE000 000040
I0526 17:46:17.201380   22828 init_comm.go:68] [console] ACPI: SSDT 0x0000000007FFEC4E 0009C2 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
I0526 17:46:17.202139   22828 init_comm.go:68] [console] ACPI: APIC 0x0000000007FFF610 000078 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
I0526 17:46:17.202399   22828 init_comm.go:68] [console] No NUMA configuration found
I0526 17:46:17.202953   22828 init_comm.go:68] [console] Faking a node at [mem 0x0000000000000000-0x0000000007ffdfff]
I0526 17:46:17.203434   22828 init_comm.go:68] [console] NODE_DATA(0) allocated [mem 0x07dc8000-0x07dd9fff]
I0526 17:46:17.203839   22828 init_comm.go:68] [console] kvm-clock: Using msrs 4b564d01 and 4b564d00
I0526 17:46:17.204304   22828 init_comm.go:68] [console] kvm-clock: cpu 0, msr 0:7ffd001, primary cpu clock
I0526 17:46:17.204775   22828 init_comm.go:68] [console] kvm-clock: using sched offset of 1431406850 cycles
I0526 17:46:17.205732   22828 init_comm.go:68] [console] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
I0526 17:46:17.205861   22828 init_comm.go:68] [console] Zone ranges:
I0526 17:46:17.206362   22828 init_comm.go:68] [console]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
I0526 17:46:17.206873   22828 init_comm.go:68] [console]   DMA32    [mem 0x0000000001000000-0x0000000007ffdfff]
I0526 17:46:17.207042   22828 init_comm.go:68] [console]   Normal   empty
I0526 17:46:17.207353   22828 init_comm.go:68] [console] Movable zone start for each node
I0526 17:46:17.219602   22828 init_comm.go:68] [console] Early memory node ranges
I0526 17:46:17.220117   22828 init_comm.go:68] [console]   node   0: [mem 0x0000000000001000-0x000000000009efff]
I0526 17:46:17.220632   22828 init_comm.go:68] [console]   node   0: [mem 0x0000000000100000-0x0000000007ffdfff]
I0526 17:46:17.221224   22828 init_comm.go:68] [console] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffdfff]
I0526 17:46:17.221514   22828 init_comm.go:68] [console] ACPI: PM-Timer IO Port: 0x608
I0526 17:46:17.221964   22828 init_comm.go:68] [console] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
I0526 17:46:17.222543   22828 init_comm.go:68] [console] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
I0526 17:46:17.223070   22828 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
I0526 17:46:17.223617   22828 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
I0526 17:46:17.224169   22828 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
I0526 17:46:17.224735   22828 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
I0526 17:46:17.225306   22828 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
I0526 17:46:17.225785   22828 init_comm.go:68] [console] Using ACPI (MADT) for SMP configuration information
I0526 17:46:17.226158   22828 init_comm.go:68] [console] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
I0526 17:46:17.226705   22828 init_comm.go:68] [console] e820: [mem 0x08000000-0xfeffbfff] available for PCI devices
I0526 17:46:17.227055   22828 init_comm.go:68] [console] Booting paravirtualized kernel on KVM
I0526 17:46:17.228004   22828 init_comm.go:68] [console] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
I0526 17:46:17.228633   22828 init_comm.go:68] [console] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_ids:1
I0526 17:46:17.229344   22828 init_comm.go:68] [console] PERCPU: Embedded 31 pages/cpu @ffff880007a00000 s89496 r8192 d29288 u2097152
I0526 17:46:17.229612   22828 init_comm.go:68] [console] KVM setup async PF for cpu 0
I0526 17:46:17.229933   22828 init_comm.go:68] [console] kvm-stealtime: cpu 0, msr 7a0d480
I0526 17:46:17.230619   22828 init_comm.go:68] [console] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 32135
I0526 17:46:17.230800   22828 init_comm.go:68] [console] Policy zone: DMA32
I0526 17:46:17.231335   22828 init_comm.go:68] [console] Kernel command line: console=ttyS0 panic=1 no_timer_check
I0526 17:46:17.243816   22828 init_comm.go:68] [console] PID hash table entries: 512 (order: 0, 4096 bytes)
I0526 17:46:17.245050   22828 init_comm.go:68] [console] Memory: 118064K/130672K available (4306K kernel code, 548K rwdata, 1400K rodata, 860K init, 756K bss, 12608K reserved, 0K cma-reserved)
I0526 17:46:17.245341   22828 init_comm.go:68] [console] Hierarchical RCU implementation.
I0526 17:46:17.245752   22828 init_comm.go:68] [console]    Build-time adjustment of leaf fanout to 64.
I0526 17:46:17.246233   22828 init_comm.go:68] [console]    RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=1.
I0526 17:46:17.246781   22828 init_comm.go:68] [console] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
I0526 17:46:17.247045   22828 init_comm.go:68] [console] NR_IRQS:4352 nr_irqs:256 16
I0526 17:46:17.247300   22828 init_comm.go:68] [console] Console: colour *CGA 80x25
I0526 17:46:17.247534   22828 init_comm.go:68] [console] console [ttyS0] enabled
I0526 17:46:17.247937   22828 init_comm.go:68] [console] tsc: Detected 3092.974 MHz processor
I0526 17:46:17.248677   22828 init_comm.go:68] [console] Calibrating delay loop (skipped) preset value.. 6185.94 BogoMIPS (lpj=3092974)
I0526 17:46:17.249023   22828 init_comm.go:68] [console] pid_max: default: 32768 minimum: 301
I0526 17:46:17.249306   22828 init_comm.go:68] [console] ACPI: Core revision 20150930
I0526 17:46:17.250738   22828 init_comm.go:68] [console] ACPI: 2 ACPI AML tables successfully acquired and loaded
I0526 17:46:17.251370   22828 init_comm.go:68] [console] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
I0526 17:46:17.252016   22828 init_comm.go:68] [console] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
I0526 17:46:17.252622   22828 init_comm.go:68] [console] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
I0526 17:46:17.253228   22828 init_comm.go:68] [console] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
I0526 17:46:17.253767   22828 init_comm.go:68] [console] Initializing cgroup subsys io
I0526 17:46:17.254101   22828 init_comm.go:68] [console] Initializing cgroup subsys memory
I0526 17:46:17.254450   22828 init_comm.go:68] [console] Initializing cgroup subsys devices
I0526 17:46:17.254784   22828 init_comm.go:68] [console] Initializing cgroup subsys freezer
I0526 17:46:17.255135   22828 init_comm.go:68] [console] Initializing cgroup subsys net_cls
I0526 17:46:17.267508   22828 init_comm.go:68] [console] Initializing cgroup subsys perf_event
I0526 17:46:17.267810   22828 init_comm.go:68] [console] Initializing cgroup subsys pids
I0526 17:46:17.268127   22828 init_comm.go:68] [console] Initializing cgroup subsys debug
I0526 17:46:17.268659   22828 init_comm.go:68] [console] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8
I0526 17:46:17.269185   22828 init_comm.go:68] [console] Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0
I0526 17:46:17.291237   22828 init_comm.go:68] [console] Freeing SMP alternatives memory: 20K (ffffffff816f6000 - ffffffff816fb000)
I0526 17:46:17.300636   22828 init_comm.go:68] [console] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
I0526 17:46:17.301564   22828 init_comm.go:68] [console] smpboot: CPU0: Intel(R) Core(TM) i5-2400 CPU @ 3.10GHz (family: 0x6, model: 0x2a, stepping: 0x7)
I0526 17:46:17.302316   22828 init_comm.go:68] [console] Performance Events: 16-deep LBR, SandyBridge events, Intel PMU driver.
I0526 17:46:17.302993   22828 init_comm.go:68] [console] perf_event_intel: PEBS disabled due to CPU errata, please upgrade microcode
I0526 17:46:17.303286   22828 init_comm.go:68] [console] ... version:                2
I0526 17:46:17.307588   22828 init_comm.go:68] [console] ... bit width:              48
I0526 17:46:17.307874   22828 init_comm.go:68] [console] ... generic registers:      8
I0526 17:46:17.308269   22828 init_comm.go:68] [console] ... value mask:             0000ffffffffffff
I0526 17:46:17.308679   22828 init_comm.go:68] [console] ... max period:             000000007fffffff
I0526 17:46:17.308968   22828 init_comm.go:68] [console] ... fixed-purpose events:   3
I0526 17:46:17.309356   22828 init_comm.go:68] [console] ... event mask:             00000007000000ff
I0526 17:46:17.309915   22828 init_comm.go:68] [console] x86: Booted up 1 node, 1 CPUs
I0526 17:46:17.310460   22828 init_comm.go:68] [console] smpboot: Total of 1 processors activated (6185.94 BogoMIPS)
I0526 17:46:17.311196   22828 init_comm.go:68] [console] devtmpfs: initialized
I0526 17:46:17.321866   22828 init_comm.go:68] [console] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
I0526 17:46:17.322861   22828 init_comm.go:68] [console] NET: Registered protocol family 16
I0526 17:46:17.323554   22828 init_comm.go:68] [console] cpuidle: using governor ladder
I0526 17:46:17.324146   22828 init_comm.go:68] [console] cpuidle: using governor menu
I0526 17:46:17.324753   22828 init_comm.go:68] [console] ACPI: bus type PCI registered
I0526 17:46:17.325324   22828 init_comm.go:68] [console] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
I0526 17:46:17.326246   22828 init_comm.go:68] [console] PCI: Using configuration type 1 for base access
I0526 17:46:17.327826   22828 init_comm.go:68] [console] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off
I0526 17:46:17.331997   22828 init_comm.go:68] [console] ACPI: Added _OSI(Module Device)
I0526 17:46:17.332788   22828 init_comm.go:68] [console] ACPI: Added _OSI(Processor Device)
I0526 17:46:17.333646   22828 init_comm.go:68] [console] ACPI: Added _OSI(3.0 _SCP Extensions)
I0526 17:46:17.334673   22828 init_comm.go:68] [console] ACPI: Added _OSI(Processor Aggregator Device)
I0526 17:46:17.347770   22828 init_comm.go:68] [console] ACPI: Interpreter enabled
I0526 17:46:17.348329   22828 init_comm.go:68] [console] ACPI: (supports S0 S5)
I0526 17:46:17.349249   22828 init_comm.go:68] [console] ACPI: Using IOAPIC for interrupt routing
I0526 17:46:17.351196   22828 init_comm.go:68] [console] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
I0526 17:46:17.354573   22828 init_comm.go:68] [console] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
I0526 17:46:17.355989   22828 init_comm.go:68] [console] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
I0526 17:46:17.357335   22828 init_comm.go:68] [console] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
I0526 17:46:17.358110   22828 init_comm.go:68] [console] acpiphp: Slot [2] registered
I0526 17:46:17.358809   22828 init_comm.go:68] [console] acpiphp: Slot [3] registered
I0526 17:46:17.359530   22828 init_comm.go:68] [console] acpiphp: Slot [4] registered
I0526 17:46:17.360351   22828 init_comm.go:68] [console] acpiphp: Slot [5] registered
I0526 17:46:17.361158   22828 init_comm.go:68] [console] acpiphp: Slot [6] registered
I0526 17:46:17.361963   22828 init_comm.go:68] [console] acpiphp: Slot [7] registered
I0526 17:46:17.362763   22828 init_comm.go:68] [console] acpiphp: Slot [8] registered
I0526 17:46:17.363564   22828 init_comm.go:68] [console] acpiphp: Slot [9] registered
I0526 17:46:17.364390   22828 init_comm.go:68] [console] acpiphp: Slot [10] registered
I0526 17:46:17.365211   22828 init_comm.go:68] [console] acpiphp: Slot [11] registered
I0526 17:46:17.366038   22828 init_comm.go:68] [console] acpiphp: Slot [12] registered
I0526 17:46:17.366865   22828 init_comm.go:68] [console] acpiphp: Slot [13] registered
I0526 17:46:17.367695   22828 init_comm.go:68] [console] acpiphp: Slot [14] registered
I0526 17:46:17.380071   22828 init_comm.go:68] [console] acpiphp: Slot [15] registered
I0526 17:46:17.380912   22828 init_comm.go:68] [console] acpiphp: Slot [16] registered
I0526 17:46:17.381735   22828 init_comm.go:68] [console] acpiphp: Slot [17] registered
I0526 17:46:17.382565   22828 init_comm.go:68] [console] acpiphp: Slot [18] registered
I0526 17:46:17.383387   22828 init_comm.go:68] [console] acpiphp: Slot [19] registered
I0526 17:46:17.384223   22828 init_comm.go:68] [console] acpiphp: Slot [20] registered
I0526 17:46:17.385047   22828 init_comm.go:68] [console] acpiphp: Slot [21] registered
I0526 17:46:17.385872   22828 init_comm.go:68] [console] acpiphp: Slot [22] registered
I0526 17:46:17.386692   22828 init_comm.go:68] [console] acpiphp: Slot [23] registered
I0526 17:46:17.387529   22828 init_comm.go:68] [console] acpiphp: Slot [24] registered
I0526 17:46:17.388356   22828 init_comm.go:68] [console] acpiphp: Slot [25] registered
I0526 17:46:17.389182   22828 init_comm.go:68] [console] acpiphp: Slot [26] registered
I0526 17:46:17.390008   22828 init_comm.go:68] [console] acpiphp: Slot [27] registered
I0526 17:46:17.390835   22828 init_comm.go:68] [console] acpiphp: Slot [28] registered
I0526 17:46:17.391665   22828 init_comm.go:68] [console] acpiphp: Slot [29] registered
I0526 17:46:17.392494   22828 init_comm.go:68] [console] acpiphp: Slot [30] registered
I0526 17:46:17.393326   22828 init_comm.go:68] [console] acpiphp: Slot [31] registered
I0526 17:46:17.394162   22828 init_comm.go:68] [console] PCI host bridge to bus 0000:00
I0526 17:46:17.395704   22828 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
I0526 17:46:17.397250   22828 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
I0526 17:46:17.398977   22828 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
I0526 17:46:17.400712   22828 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x08000000-0xfebfffff window]
I0526 17:46:17.401908   22828 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [bus 00-ff]
I0526 17:46:17.418268   22828 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
I0526 17:46:17.418369   22828 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
I0526 17:46:17.418406   22828 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
I0526 17:46:17.418437   22828 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
I0526 17:46:17.419420   22828 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
I0526 17:46:17.421039   22828 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
I0526 17:46:17.460650   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
I0526 17:46:17.462117   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
I0526 17:46:17.463485   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
I0526 17:46:17.464845   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
I0526 17:46:17.466007   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
I0526 17:46:17.467295   22828 init_comm.go:68] [console] ACPI: Enabled 16 GPEs in block 00 to 0F
I0526 17:46:17.467867   22828 init_comm.go:68] [console] vgaarb: loaded
I0526 17:46:17.468665   22828 init_comm.go:68] [console] SCSI subsystem initialized
I0526 17:46:17.469545   22828 init_comm.go:68] [console] PCI: Using ACPI for IRQ routing
I0526 17:46:17.470967   22828 init_comm.go:68] [console] clocksource: Switched to clocksource kvm-clock
I0526 17:46:17.471617   22828 init_comm.go:68] [console] pnp: PnP ACPI init
I0526 17:46:17.472813   22828 init_comm.go:68] [console] pnp: PnP ACPI: found 5 devices
I0526 17:46:17.521474   22828 init_comm.go:68] [console] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
I0526 17:46:17.522508   22828 init_comm.go:68] [console] NET: Registered protocol family 2
I0526 17:46:17.524250   22828 init_comm.go:68] [console] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
I0526 17:46:17.525716   22828 init_comm.go:68] [console] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
I0526 17:46:17.527156   22828 init_comm.go:68] [console] TCP: Hash tables configured (established 1024 bind 1024)
I0526 17:46:17.528500   22828 init_comm.go:68] [console] UDP hash table entries: 256 (order: 1, 8192 bytes)
I0526 17:46:17.529919   22828 init_comm.go:68] [console] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
I0526 17:46:17.530875   22828 init_comm.go:68] [console] NET: Registered protocol family 1
I0526 17:46:17.532207   22828 init_comm.go:68] [console] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
I0526 17:46:17.533484   22828 init_comm.go:68] [console] pci 0000:00:01.0: PIIX3: Enabling Passive Release
I0526 17:46:17.534858   22828 init_comm.go:68] [console] pci 0000:00:01.0: Activating ISA DMA hang workarounds
I0526 17:46:17.536128   22828 init_comm.go:68] [console] Trying to unpack rootfs image as initramfs...
I0526 17:46:17.575384   22828 init_comm.go:68] [console] Freeing initrd memory: 2136K (ffff880007dda000 - ffff880007ff0000)
I0526 17:46:17.577117   22828 init_comm.go:68] [console] futex hash table entries: 256 (order: 2, 16384 bytes)
I0526 17:46:17.578890   22828 init_comm.go:68] [console] SGI XFS with ACLs, security attributes, no debug enabled
I0526 17:46:17.580306   22828 init_comm.go:68] [console] 9p: Installing v9fs 9p2000 file system support
I0526 17:46:17.583519   22828 init_comm.go:68] [console] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
I0526 17:46:17.584310   22828 init_comm.go:68] [console] io scheduler noop registered
I0526 17:46:17.585317   22828 init_comm.go:68] [console] io scheduler cfq registered (default)
I0526 17:46:17.586582   22828 init_comm.go:68] [console] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
I0526 17:46:17.588097   22828 init_comm.go:68] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
I0526 17:46:17.589847   22828 init_comm.go:68] [console] Warning: Processor Platform Limit event detected, but not handled.
I0526 17:46:17.591182   22828 init_comm.go:68] [console] Consider compiling CPUfreq support into your kernel.
I0526 17:46:17.612244   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
I0526 17:46:17.613874   22828 init_comm.go:68] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
I0526 17:46:17.635136   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
I0526 17:46:17.636764   22828 init_comm.go:68] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
I0526 17:46:17.657712   22828 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
I0526 17:46:17.659346   22828 init_comm.go:68] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
I0526 17:46:17.661192   22828 init_comm.go:68] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
I0526 17:46:17.748385   22828 init_comm.go:68] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
I0526 17:46:17.852834   22828 init_comm.go:68] [console] brd: module loaded
I0526 17:46:17.853038   22828 init_comm.go:68] [console] loop: module loaded
I0526 17:46:17.885837   22828 init_comm.go:68] [console] scsi host0: Virtio SCSI HBA
I0526 17:46:17.946483   22828 init_comm.go:68] [console] rtc_cmos 00:00: RTC can wake from S4
I0526 17:46:17.947186   22828 init_comm.go:68] [console] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
I0526 17:46:17.947774   22828 init_comm.go:68] [console] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
I0526 17:46:17.948176   22828 init_comm.go:68] [console] NET: Registered protocol family 10
I0526 17:46:17.948665   22828 init_comm.go:68] [console] NET: Registered protocol family 17
I0526 17:46:17.948987   22828 init_comm.go:68] [console] 9pnet: Installing 9P2000 support
I0526 17:46:17.993684   22828 init_comm.go:68] [console] registered taskstats version 1
I0526 17:46:17.994626   22828 init_comm.go:68] [console] rtc_cmos 00:00: setting system clock to 2016-05-26 09:46:17 UTC (1464255977)
I0526 17:46:17.995994   22828 init_comm.go:68] [console] Freeing unused kernel memory: 860K (ffffffff8161f000 - ffffffff816f6000)
I0526 17:46:17.996554   22828 init_comm.go:68] [console] create directory /sys
I0526 17:46:17.996789   22828 init_comm.go:68] [console] create directory /sbin
I0526 17:46:17.997030   22828 init_comm.go:68] [console] create directory /proc
I0526 17:46:17.997249   22828 init_comm.go:68] [console] uptime 0.62 0.02
I0526 17:46:17.997335   22828 init_comm.go:68] [console] 
I0526 17:46:17.997618   22828 init_comm.go:68] [console] create directory /dev/pts
I0526 17:46:17.997986   22828 init_comm.go:68] [console] open hyper channel /dev/vport0p1
I0526 17:46:17.998232   22828 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1464255977, "microseconds": 998055}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel0"}}
I0526 17:46:17.998297   22828 qmp_handler.go:107] got event: VSERPORT_CHANGE
I0526 17:46:17.998345   22828 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
I0526 17:46:18.000540   22828 init_comm.go:68] [console] send ready message
I0526 17:46:18.000773   22828 init_comm.go:68] [console] hyper send type 8, len 0
I0526 17:46:18.000847   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.000892   22828 init_comm.go:110] data length is 8
I0526 17:46:18.000925   22828 init_comm.go:143] Get init ready message
I0526 17:46:18.000985   22828 init_comm.go:190] got cmd:1
I0526 17:46:18.001053   22828 init_comm.go:281] send command 1 to init, payload: '{"hostname":"68988a52009d","containers":[],"shareDir":"share_dir"}'.
I0526 17:46:18.001098   22828 init_comm.go:294] write 74 to init, payload: 'J{"hostname":"68988a52009d","containers":[],"shareDir":"share_dir"}'.
I0526 17:46:18.001145   22828 init_comm.go:299] message sent, set pong timer
I0526 17:46:18.001015   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.001001   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 5(EVENT_INIT_CONNECTED)
I0526 17:46:18.001415   22828 vm_states.go:490] begin to wait vm commands
I0526 17:46:18.001469   22828 vm.go:260] Get the response from VM, VM id is vm-pEwxFWdQnA!
I0526 17:46:18.011911   22828 init_comm.go:68] [console] channel sh.hyper.channel.1, directory sh.hyper.channel.0
I0526 17:46:18.011976   22828 init_comm.go:68] [console] 
I0526 17:46:18.012271   22828 init_comm.go:68] [console] open hyper channel /dev/vport0p2
I0526 17:46:18.012852   22828 init_comm.go:68] [console] hyper_init_event hyper channel event 0x6165c0, ops 0x6163c0, fd 3
I0526 17:46:18.013196   22828 init_comm.go:68] [console] hyper_add_event add event fd 3, 0x6163c0
I0526 17:46:18.013667   22828 init_comm.go:68] [console] hyper_init_event hyper ttyfd event 0x616588, ops 0x616380, fd 4
I0526 17:46:18.014006   22828 init_comm.go:68] [console] hyper_add_event add event fd 4, 0x616380
I0526 17:46:18.014244   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:18.014706   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 17:46:18.015172   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 17:46:18.015359   22828 init_comm.go:68] [console] hyper_event_read
I0526 17:46:18.015603   22828 init_comm.go:68] [console] already read 8 bytes data
I0526 17:46:18.015841   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:18.015938   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.015956   22828 init_comm.go:110] data length is 12
I0526 17:46:18.015980   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:18.016007   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:18.016022   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.016040   22828 init_comm.go:190] got cmd:14
I0526 17:46:18.016068   22828 init_comm.go:253] get command NEXT
I0526 17:46:18.016077   22828 init_comm.go:256] send 74, receive 8
I0526 17:46:18.016054   22828 init_comm.go:68] [console] get length 74
I0526 17:46:18.016336   22828 init_comm.go:68] [console] read 66 bytes data, total data 74
I0526 17:46:18.016570   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:18.016633   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.016672   22828 init_comm.go:110] data length is 12
I0526 17:46:18.016703   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:18.016740   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:18.016775   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.016815   22828 init_comm.go:190] got cmd:14
I0526 17:46:18.016847   22828 init_comm.go:253] get command NEXT
I0526 17:46:18.016881   22828 init_comm.go:256] send 74, receive 74
I0526 17:46:18.017950   22828 init_comm.go:68] [console] 0 0 0 1 0 0 0 4a 7b 22 68 6f 73 74 6e 61 6d 65 22 3a 22 36 38 39 38 38 61 35 32 30 30 39 64 22 2c 22 63 6f 6e 74 61 69 6e 65 72 73 22 3a 5b 5d 2c 22 73 68 61 72 65 44 69 72 22 3a 22 73 68 61 72 65 5f 64 69 72 22 7d 
I0526 17:46:18.018257   22828 init_comm.go:68] [console]  hyper_channel_handle, type 1, len 74
I0526 17:46:18.018957   22828 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"68988a52009d","containers":[],"shareDir":"share_dir"}, len 66
I0526 17:46:18.040241   22828 init_comm.go:68] [console] random: busybox urandom read with 7 bits of entropy available
I0526 17:46:18.041122   22828 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"68988a52009d","containers":[],"shareDir":"share_dir"}, len 66
I0526 17:46:18.041385   22828 init_comm.go:68] [console] jsmn parse successed, n is 7
I0526 17:46:18.041642   22828 init_comm.go:68] [console] token 0, type is 1, size is 3
I0526 17:46:18.041906   22828 init_comm.go:68] [console] token 1, type is 3, size is 1
I0526 17:46:18.042144   22828 init_comm.go:68] [console] hostname is 68988a52009d
I0526 17:46:18.042405   22828 init_comm.go:68] [console] token 3, type is 3, size is 1
I0526 17:46:18.042594   22828 init_comm.go:68] [console] container count 0
I0526 17:46:18.042846   22828 init_comm.go:68] [console] token 5, type is 3, size is 1
I0526 17:46:18.043078   22828 init_comm.go:68] [console] share tag is share_dir
I0526 17:46:18.043303   22828 init_comm.go:68] [console] create directory /tmp
I0526 17:46:18.043562   22828 init_comm.go:68] [console] create directory /tmp/hyper
I0526 17:46:18.043839   22828 init_comm.go:68] [console] create directory /tmp/hyper/proc
I0526 17:46:18.044227   22828 init_comm.go:68] [console] finish rescan
I0526 17:46:18.044624   22828 init_comm.go:68] [console] create directory /tmp/hyper/shared
I0526 17:46:18.067861   22828 init_comm.go:68] [console] pod init pid 325
I0526 17:46:18.068181   22828 init_comm.go:68] [console] hyper send type 8, len 0
I0526 17:46:18.068390   22828 init_comm.go:68] [console] uptime 0.69 0.03
I0526 17:46:18.068476   22828 init_comm.go:68] [console] 
I0526 17:46:18.068715   22828 init_comm.go:68] [console] hyper send type 9, len 0
I0526 17:46:18.068797   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.068813   22828 init_comm.go:110] data length is 8
I0526 17:46:18.068824   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.068841   22828 init_comm.go:190] got cmd:9
I0526 17:46:18.068856   22828 init_comm.go:209] ack got, clear pong timer
I0526 17:46:18.068871   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 31(COMMAND_ACK)
I0526 17:46:18.068885   22828 vm_states.go:500] [starting] got init ack to &{1 859533981568 <nil> [] 859532519968}
I0526 17:46:18.069014   22828 init_comm.go:68] [console] pid 324 exit normally, status 0
I0526 17:46:18.069033   22828 context.go:211] VM vm-pEwxFWdQnA: state change from STARTING to 'RUNNING'
I0526 17:46:18.069049   22828 vm_states.go:516] pod start success 
I0526 17:46:18.069068   22828 vm.go:260] Get the response from VM, VM id is vm-pEwxFWdQnA!
I0526 17:46:18.069086   22828 hyperpod.go:319] result: code 0 Start POD success
I0526 17:46:18.069098   22828 hyperpod.go:185] get exec path /home/darcy/gocode/src/github.com/hyperhq/runv/runv-containerd
I0526 17:46:18.069398   22828 init_comm.go:68] [console] can not find exec whose pid is 324
I0526 17:46:18.069526   22828 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0526 17:46:18.109406   22828 hyperpod.go:234] nsListener pid is 23581
I0526 17:46:18.109437   22828 supervisor.go:168] createHyperPod() returns
I0526 17:46:18.109448   22828 hyperpod.go:257] createContainer()
I0526 17:46:18.109458   22828 process.go:33] process setupIO: stdin /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stdin, stdout /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stdout, stderr /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stderr
I0526 17:46:18.109493   22828 process.go:59] process setupIO() success
I0526 17:46:18.109504   22828 hyperpod.go:283] createContainer()
I0526 17:46:18.109512   22828 hyperpod.go:289] createContainer() calls c.run(p)
I0526 17:46:18.109533   22828 supervisor.go:53] Supervisor.CreateContainer() return: c:&{68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b 0xc8204a4000 map[init:0xc82017f200] 0xc8204fc700} p:&{init /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stdin /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stdout /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/init-stderr 0xc8204a4030 -1 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b-init 0xc8204fc880 true 0xc8204fc8c0 <nil>}
I0526 17:46:18.109571   22828 server.go:50] end Supervisor.CreateContainer(), build api Container
I0526 17:46:18.109583   22828 server.go:55] gRPC respond CreateContainer
I0526 17:46:18.109682   22828 container.go:64] save state id 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b, boundle /var/run/docker/libcontainerd/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.109773   22828 container.go:95] prepare hypervisor info
I0526 17:46:18.109785   22828 ocf-linux.go:21] env: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
I0526 17:46:18.109796   22828 ocf-linux.go:21] env: HOSTNAME=68988a52009d
I0526 17:46:18.109804   22828 ocf-linux.go:21] env: TERM=xterm
I0526 17:46:18.109871   22828 container.go:311] Skip mount point "/proc" of type proc
I0526 17:46:18.109894   22828 container.go:311] Skip mount point "/dev" of type tmpfs
I0526 17:46:18.129457   22828 container.go:311] Skip mount point "/sys" of type sysfs
I0526 17:46:18.129490   22828 container.go:311] Skip mount point "/sys/fs/cgroup" of type cgroup
I0526 17:46:18.129502   22828 container.go:311] Skip mount point "/dev/mqueue" of type mqueue
I0526 17:46:18.160401   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 34(GENERIC_OPERATION)
I0526 17:46:18.160436   22828 vm_states.go:303] handle GenericOperation(Attach) on state(RUNNING)
I0526 17:46:18.160446   22828 context.go:179] can not found container 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.160457   22828 vm_states.go:220] attachment 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b-init is pending
I0526 17:46:18.357088   22828 hyperpod.go:127] interface configuration of pod ns is [{508 0 172.17.0.3/16}]
E0526 17:46:18.357548   22828 hyperpod.go:131] cann't find nic whose ifindex is 0
I0526 17:46:18.357606   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 34(GENERIC_OPERATION)
I0526 17:46:18.357651   22828 vm_states.go:303] handle GenericOperation(AddRoute) on state(RUNNING)
I0526 17:46:18.357691   22828 events.go:121] notifySubscribers: {68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b start-container 2016-05-26 17:46:18.357688822 +0800 CST  0}
I0526 17:46:18.357752   22828 events.go:54] write event log: {68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b start-container 2016-05-26 17:46:18.357688822 +0800 CST  0}
I0526 17:46:18.357819   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 26(COMMAND_NEWCONTAINER)
I0526 17:46:18.357867   22828 context.go:175] found container 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b at 0
I0526 17:46:18.357961   22828 vm_states.go:114] attach pending client 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b-init for 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.358004   22828 vm_states.go:239] Connecting tty for 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b on session 1
I0526 17:46:18.358040   22828 vm_states.go:127] start sending INIT_NEWCONTAINER
I0526 17:46:18.358074   22828 vm_states.go:132] sent INIT_NEWCONTAINER
I0526 17:46:18.358119   22828 init_comm.go:190] got cmd:17
I0526 17:46:18.358180   22828 init_comm.go:281] send command 17 to init, payload: '{"id":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","rootfs":"rootfs","image":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"env":"HOSTNAME","value":"68988a52009d"},{"env":"TERM","value":"xterm"}],"workdir":"/"},"restartPolicy":"never","initialize":false}'.
I0526 17:46:18.358236   22828 init_comm.go:294] write 451 to init, payload: '»"id":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","rootfs":"rootfs","image":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"env":"HOSTNAME","value":"68988a52009d"},{"env":"TERM","value":"xterm"}],"workdir":"/"},"restartPolicy":"never","initialize":false}'.
I0526 17:46:18.358285   22828 init_comm.go:299] message sent, set pong timer
I0526 17:46:18.358614   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:18.360335   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 17:46:18.360372   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 17:46:18.360408   22828 init_comm.go:68] [console] hyper_event_read
I0526 17:46:18.360440   22828 init_comm.go:68] [console] already read 8 bytes data
I0526 17:46:18.360484   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:18.360273   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.360549   22828 init_comm.go:110] data length is 12
I0526 17:46:18.360580   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:18.360617   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:18.360658   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.360700   22828 init_comm.go:190] got cmd:14
I0526 17:46:18.360735   22828 init_comm.go:253] get command NEXT
I0526 17:46:18.360766   22828 init_comm.go:256] send 451, receive 8
I0526 17:46:18.362609   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.362709   22828 init_comm.go:110] data length is 12
I0526 17:46:18.362718   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:18.362729   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:18.362740   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.362751   22828 init_comm.go:190] got cmd:14
I0526 17:46:18.362760   22828 init_comm.go:253] get command NEXT
I0526 17:46:18.362768   22828 init_comm.go:256] send 451, receive 451
I0526 17:46:18.362691   22828 init_comm.go:68] [console] get length 451
I0526 17:46:18.362790   22828 init_comm.go:68] [console] read 443 bytes data, total data 451
I0526 17:46:18.362799   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:18.395866   22828 init_comm.go:68] [console] 0 0 0 11 0 0 1 c3 7b 22 69 64 22 3a 22 36 38 39 38 38 61 35 32 30 30 39 64 38 38 35 64 35 39 62 36 39 30 64 33 36 61 34 37 64 30 33 33 65 32 65 61 39 32 31 32 38 37 31 63 33 32 37 35 34 34 36 64 37 39 32 36 35 63 61 37 34 66 30 62 22 2c 22 72 6f 6f 74 66 73 22 3a 22 72 6f 6f 74 66 73 22 2c 22 69 6d 61 67 65 22 3a 22 36 38 39 38 38 61 35 32 30 30 39 64 38 38 35 64 35 39 62 36 39 30 64 33 36 61 34 37 64 30 33 33 65 32 65 61 39 32 31 32 38 37 31 63 33 32 37 35 34 34 36 64 37 39 32 36 35 63 61 37 34 66 30 62 22 2c 22 70 72 6f 63 65 73 73 22 3a 7b 22 74 65 72 6d 69 6e 61 6c 22 3a 74 72 75 65 2c 22 73 74 64 69 6f 22 3a 31 2c 22 61 72 67 73 22 3a 5b 22 73 68 22 5d 2c 22 65 6e 76 73 22 3a 5b 7b 22 65 6e 76 22 3a 22 50 41 54 48 22 2c 22 76 61 6c 75 65 22 3a 22 2f 75 73 72 2f 6c 6f 63 61 6c 2f 73 62 69 6e 3a 2f 75 73 72 2f 6c 6f 63 61 6c 2f 62 69 6e 3a 2f 75 73 72 2f 73 62 69 6e 3a 2f 75 73 72 2f 62 69 6e 3a 2f 73 62 69 6e 3a 2f 62 69 6e 22 7d 2c 7b 22 65 6e 76 22 3a 22 48 4f 53 54 4e 41 4d 45 22 2c 22 76 61 6c 75 65 22 3a 22 36 38 39 38 38 61 35 32 30 30 39 64 22 7d 2c 7b 22 65 6e 76 22 3a 22 54 45 52 4d 22 2c 22 76 61 6c 75 65 22 3a 22 78 74 65 72 6d 22 7d 5d 2c 22 77 6f 72 6b 64 69 72 22 3a 22 2f 22 7d 2c 22 72 65 73 74 61 72 74 50 6f 6c 69 63 79 22 3a 22 6e 65 76 65 72 22 2c 22 69 6e 69 74 69 61 6c 69 7a 65 22 3a 66 61 6c 73 65 7d 
I0526 17:46:18.396862   22828 init_comm.go:68] [console]  hyper_channel_handle, type 17, len 451
I0526 17:46:18.406461   22828 init_comm.go:68] [console] call hyper_new_container, json {"id":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","rootfs":"rootfs","image":"68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b","process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"env":"HOSTNAME","value":"68988a52009d"},{"env":"TERM","value":"xterm"}],"workdir":"/"},"restartPolicy":"never","initialize":false}, len 443
I0526 17:46:18.406988   22828 init_comm.go:68] [console] next container 6
I0526 17:46:18.407357   22828 init_comm.go:68] [console] 1 name id
I0526 17:46:18.419686   22828 init_comm.go:68] [console] container id 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.420139   22828 init_comm.go:68] [console] 3 name rootfs
I0526 17:46:18.420782   22828 init_comm.go:68] [console] container rootfs rootfs
I0526 17:46:18.421208   22828 init_comm.go:68] [console] 5 name image
I0526 17:46:18.422940   22828 init_comm.go:68] [console] container image 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.423408   22828 init_comm.go:68] [console] 7 name process
I0526 17:46:18.423882   22828 init_comm.go:68] [console] 1 name terminal
I0526 17:46:18.424526   22828 init_comm.go:68] [console] container uses terminal
I0526 17:46:18.424954   22828 init_comm.go:68] [console] 3 name stdio
I0526 17:46:18.425421   22828 init_comm.go:68] [console] container seq 1
I0526 17:46:18.425823   22828 init_comm.go:68] [console] 5 name args
I0526 17:46:18.426468   22828 init_comm.go:68] [console] container init arg 0 sh
I0526 17:46:18.426875   22828 init_comm.go:68] [console] 8 name envs
I0526 17:46:18.427267   22828 init_comm.go:68] [console] envs num 3
I0526 17:46:18.427744   22828 init_comm.go:68] [console] envs 0 env PATH
I0526 17:46:18.429369   22828 init_comm.go:68] [console] envs 0 value /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
I0526 17:46:18.429944   22828 init_comm.go:68] [console] envs 1 env HOSTNAME
I0526 17:46:18.430621   22828 init_comm.go:68] [console] envs 1 value 68988a52009d
I0526 17:46:18.431105   22828 init_comm.go:68] [console] envs 2 env TERM
I0526 17:46:18.431645   22828 init_comm.go:68] [console] envs 2 value xterm
I0526 17:46:18.432131   22828 init_comm.go:68] [console] 25 name workdir
I0526 17:46:18.432686   22828 init_comm.go:68] [console] container workdir /
I0526 17:46:18.433295   22828 init_comm.go:68] [console] 35 name restartPolicy
I0526 17:46:18.433884   22828 init_comm.go:68] [console] restart policy never
I0526 17:46:18.434439   22828 init_comm.go:68] [console] 37 name initialize
I0526 17:46:18.436552   22828 init_comm.go:68] [console] create directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b
I0526 17:46:18.438703   22828 init_comm.go:68] [console] create directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/devpts
I0526 17:46:18.440873   22828 init_comm.go:68] [console] create directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/devpts/
I0526 17:46:18.453553   22828 init_comm.go:68] [console] get pty device for exec /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/devpts//0
I0526 17:46:18.454724   22828 init_comm.go:68] [console] hyper_setup_exec_tty pts event 0xc4f898, fd 13 14
I0526 17:46:18.456227   22828 init_comm.go:68] [console] hyper_init_event container pts event 0xc4f898, ops 0x616500, fd 13
I0526 17:46:18.457232   22828 init_comm.go:68] [console] hyper_add_event add event fd 13, 0x616500
I0526 17:46:18.458236   22828 init_comm.go:68] [console] hyper_add_event add event fd 15, 0x6164c0
I0526 17:46:18.459240   22828 init_comm.go:68] [console] hyper_add_event add event fd 16, 0x616480
I0526 17:46:18.460071   22828 init_comm.go:68] [console] hyper_container_init in
I0526 17:46:18.461021   22828 init_comm.go:68] [console] path /sys/class/scsi_host/host0/scan
I0526 17:46:18.497344   22828 init_comm.go:68] [console] finish scan scsi
I0526 17:46:18.497435   22828 init_comm.go:68] [console] create directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/root
I0526 17:46:18.497475   22828 init_comm.go:68] [console] create directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/root/
I0526 17:46:18.498378   22828 init_comm.go:68] [console] container root directory /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/root/
I0526 17:46:18.500361   22828 init_comm.go:68] [console] src directory /tmp/hyper/shared/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/
I0526 17:46:18.503360   22828 init_comm.go:68] [console] root directory for container is /tmp/hyper/68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b/root//rootfs, init task sh
I0526 17:46:18.536320   22828 init_comm.go:68] [console] create directory ./lib
I0526 17:46:18.536949   22828 init_comm.go:68] [console] create directory ./lib/modules
I0526 17:46:18.538114   22828 init_comm.go:68] [console] create directory ./dev/shm
I0526 17:46:18.539572   22828 init_comm.go:68] [console] create directory .//lib/modules/4.4.7-hyper+
I0526 17:46:18.542064   22828 init_comm.go:68] [console] no dns configured
I0526 17:46:18.542155   22828 init_comm.go:68] [console] hyper send type 8, len 0
I0526 17:46:18.542196   22828 init_comm.go:68] [console] container 68988a52009d885d59b690d36a47d033e2ea9212871c3275446d79265ca74f0b,init pid 327,ref 4
I0526 17:46:18.542228   22828 init_comm.go:68] [console] hyper send type 8, len 0
I0526 17:46:18.542263   22828 init_comm.go:68] [console] hyper send type 9, len 0
I0526 17:46:18.542084   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:18.542315   22828 init_comm.go:110] data length is 8
I0526 17:46:18.542349   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:18.542391   22828 init_comm.go:190] got cmd:9
I0526 17:46:18.542431   22828 init_comm.go:209] ack got, clear pong timer
I0526 17:46:18.542469   22828 hypervisor.go:29] vm vm-pEwxFWdQnA: main event loop got message 31(COMMAND_ACK)
I0526 17:46:18.542518   22828 vm_states.go:562] [running] got init ack to &{17 859534740928 <nil> [] 859535645056}
I0526 17:46:18.542569   22828 vm_states.go:565] Get ack for new container
I0526 17:46:18.544583   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:18.544603   22828 init_comm.go:68] [console] hyper_handle_event get event 4, de 0xc4f898, fd 13. ops 0x616500
I0526 17:46:18.544612   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, de 0xc4f898, fd 13, 0x616500
I0526 17:46:18.544620   22828 init_comm.go:68] [console] write_to_stdin, seq 1
I0526 17:46:18.544629   22828 init_comm.go:68] [console] hyper_modify_event modify event fd 13, 0xc4f898, event 1
I0526 17:46:18.544637   22828 init_comm.go:68] [console] hyper_dup_exec_tty
I0526 17:46:18.552764   22828 init_comm.go:68] [console] hyper_loop epoll_wait 3
I0526 17:46:18.552834   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0xc4f908, fd 16. ops 0x616480
I0526 17:46:18.552869   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0xc4f908, fd 16, 0x616480
I0526 17:46:18.552900   22828 init_comm.go:68] [console] stderr_loop, seq 0
I0526 17:46:18.552931   22828 init_comm.go:68] [console] pts_loop: read 4 data
I0526 17:46:18.552961   22828 init_comm.go:68] [console] pts_loop: read -1 data
I0526 17:46:18.552992   22828 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x616588, event 5
I0526 17:46:18.553422   22828 tty.go:97] tty: read 12/12 [length = 0]
I0526 17:46:18.553437   22828 tty.go:101] data length is 16
I0526 17:46:18.553470   22828 tty.go:87] tty: trying to read 4 bytes
I0526 17:46:18.553483   22828 tty.go:97] tty: read 16/16 [length = 16]
I0526 17:46:18.553512   22828 tty.go:87] tty: trying to read 12 bytes
I0526 17:46:18.554507   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0xc4f8d0, fd 15. ops 0x6164c0
I0526 17:46:18.555738   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0xc4f8d0, fd 15, 0x6164c0
I0526 17:46:18.556158   22828 init_comm.go:68] [console] stdout_loop, seq 1
I0526 17:46:18.556635   22828 init_comm.go:68] [console] pts_loop: read -1 data
I0526 17:46:18.557885   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0xc4f898, fd 13. ops 0x616500
I0526 17:46:18.558406   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:18.559733   22828 init_comm.go:68] [console] hyper_handle_event get event 4, de 0x616588, fd 4. ops 0x616380
I0526 17:46:18.561043   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, de 0x616588, fd 4, 0x616380
I0526 17:46:18.562199   22828 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x616588, event 1
I0526 17:46:18.580148   22828 init_comm.go:68] [console] tsc: Refined TSC clocksource calibration: 3092.974 MHz
I0526 17:46:18.580209   22828 init_comm.go:68] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2c955ac38be, max_idle_ns: 440795348546 ns
I0526 17:46:18.998654   22828 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1464255978, "microseconds": 12324}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel1"}}
I0526 17:46:18.998759   22828 qmp_handler.go:107] got event: VSERPORT_CHANGE
I0526 17:46:18.998812   22828 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
I0526 17:46:24.623416   22828 init_comm.go:216] Send ping message to init
I0526 17:46:24.623526   22828 init_comm.go:190] got cmd:12
I0526 17:46:24.623584   22828 init_comm.go:281] send command 12 to init, payload: 'null'.
I0526 17:46:24.623635   22828 init_comm.go:294] write 12 to init, payload: '

                                                                            null'.
I0526 17:46:24.623672   22828 init_comm.go:299] message sent, set pong timer
I0526 17:46:24.623933   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:24.624374   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 17:46:24.624798   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 17:46:24.624964   22828 init_comm.go:68] [console] hyper_event_read
I0526 17:46:24.625203   22828 init_comm.go:68] [console] already read 8 bytes data
I0526 17:46:24.625449   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:24.625521   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:24.625559   22828 init_comm.go:110] data length is 12
I0526 17:46:24.625590   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:24.625627   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:24.625661   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:24.625699   22828 init_comm.go:190] got cmd:14
I0526 17:46:24.625773   22828 init_comm.go:253] get command NEXT
I0526 17:46:24.625808   22828 init_comm.go:256] send 12, receive 8
I0526 17:46:24.625743   22828 init_comm.go:68] [console] get length 12
I0526 17:46:24.625883   22828 init_comm.go:68] [console] read 4 bytes data, total data 12
I0526 17:46:24.626125   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:24.626184   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:24.626218   22828 init_comm.go:110] data length is 12
I0526 17:46:24.626252   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:24.626285   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:24.626340   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:24.626380   22828 init_comm.go:68] [console] 0 0 0 c 0 0 0 c 6e 75 6c 6c 
I0526 17:46:24.626380   22828 init_comm.go:190] got cmd:14
I0526 17:46:24.626404   22828 init_comm.go:253] get command NEXT
I0526 17:46:24.626415   22828 init_comm.go:256] send 12, receive 12
I0526 17:46:24.626696   22828 init_comm.go:68] [console]  hyper_channel_handle, type 12, len 12
I0526 17:46:24.626915   22828 init_comm.go:68] [console] hyper send type 9, len 0
I0526 17:46:24.626976   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:24.627013   22828 init_comm.go:110] data length is 8
I0526 17:46:24.627045   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:24.627087   22828 init_comm.go:190] got cmd:9
I0526 17:46:24.627122   22828 init_comm.go:209] ack got, clear pong timer
I0526 17:46:48.542563   22828 init_comm.go:216] Send ping message to init
I0526 17:46:48.542623   22828 init_comm.go:190] got cmd:12
I0526 17:46:48.542670   22828 init_comm.go:281] send command 12 to init, payload: 'null'.
I0526 17:46:48.542720   22828 init_comm.go:294] write 12 to init, payload: '

                                                                            null'.
I0526 17:46:48.545306   22828 init_comm.go:299] message sent, set pong timer
I0526 17:46:48.545253   22828 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0526 17:46:48.545349   22828 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x6165c0, fd 3. ops 0x6163c0
I0526 17:46:48.545373   22828 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x6165c0, fd 3, 0x6163c0
I0526 17:46:48.545539   22828 init_comm.go:68] [console] hyper_event_read
I0526 17:46:48.545569   22828 init_comm.go:68] [console] already read 8 bytes data
I0526 17:46:48.545580   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:48.545601   22828 init_comm.go:68] [console] get length 12
I0526 17:46:48.545622   22828 init_comm.go:68] [console] read 4 bytes data, total data 12
I0526 17:46:48.545506   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:48.545653   22828 init_comm.go:110] data length is 12
I0526 17:46:48.545675   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:48.545702   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:48.545733   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:48.545764   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:48.545790   22828 init_comm.go:110] data length is 12
I0526 17:46:48.545812   22828 init_comm.go:96] trying to read 4 bytes
I0526 17:46:48.545835   22828 init_comm.go:106] read 12/12 [length = 12]
I0526 17:46:48.545860   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:48.545915   22828 init_comm.go:106] read 8/8 [length = 0]
I0526 17:46:48.545941   22828 init_comm.go:110] data length is 8
I0526 17:46:48.545973   22828 init_comm.go:96] trying to read 8 bytes
I0526 17:46:48.545874   22828 init_comm.go:190] got cmd:14
I0526 17:46:48.546013   22828 init_comm.go:253] get command NEXT
I0526 17:46:48.546041   22828 init_comm.go:256] send 12, receive 8
I0526 17:46:48.546069   22828 init_comm.go:190] got cmd:14
I0526 17:46:48.546103   22828 init_comm.go:253] get command NEXT
I0526 17:46:48.546129   22828 init_comm.go:256] send 12, receive 12
I0526 17:46:48.546152   22828 init_comm.go:190] got cmd:9
I0526 17:46:48.546176   22828 init_comm.go:209] ack got, clear pong timer
I0526 17:46:48.546320   22828 init_comm.go:68] [console] hyper send type 14, len 4
I0526 17:46:48.546492   22828 init_comm.go:68] [console] 0 0 0 c 0 0 0 c 6e 75 6c 6c 
I0526 17:46:48.546723   22828 init_comm.go:68] [console]  hyper_channel_handle, type 12, len 12
I0526 17:46:48.546880   22828 init_comm.go:68] [console] hyper send type 9, len 0

reimplement xen driver via libvirt

runv-containerd: avoid block at the statemachine

#218

func (vm *Vm) AddNic(idx int, name string, info pod.UserInterface) error {
       res := vm.SendGenericOperation("AddNic", func(ctx *VmContext, result chan<- error) {
       // it runs at statemachine, the code ev, ok = <-client should be removed.
       // using multiple SendGenericOperation()s is one of the solutions.

start the qemu with go library functions

use the go library functions instead of the current utils.ExecInDaemon()
and log the stdout/stderr of the qemu
and prevent qemu from exit or error when the hyperd or runv-containerd goes to exit/panic/hup or their tty/pipe hup/fails or other cases.

It is also a preparation for lazy qemu driver.

@YaoZengzeng

runv in containerd mode spawns containerd-nslistener processes

Using runv as a containerd daemon for docker 1.12, after launching several containers a large number of left-over processes remain:

root     27214  0.0  0.0  91660  3888 pts/10   S+   17:35   0:00  |   \_ sudo runv --driver kvm --kernel=/home/will/src/go/src/github.com/hyperhq/hyperstart/build/kernel --initrd=/home/will/src/go/s
root     27215  0.3  0.0 1336248 26988 pts/10  Sl+  17:35   0:05  |       \_ runv --driver kvm --kernel=/home/will/src/go/src/github.com/hyperhq/hyperstart/build/kernel --initrd=/home/will/src/go/sr
root     27426  0.0  0.0 293048  9420 pts/10   Sl+  17:35   0:00  |           \_ containerd-nslistener
root     27929  0.0  0.0 291896  9708 pts/10   Sl+  17:35   0:00  |           \_ containerd-nslistener
root     30322  0.0  0.0 367036  7764 pts/10   Sl+  17:46   0:00  |           \_ containerd-nslistener
root     30604  0.0  0.0 358840  9876 pts/10   Sl+  17:46   0:00  |           \_ containerd-nslistener
root     31968  0.0  0.0 291896  9940 pts/10   Sl+  17:50   0:00  |           \_ containerd-nslistener
root     32234  0.0  0.0 227512  7796 pts/10   Sl+  17:50   0:00  |           \_ containerd-nslistener
root     32747  0.0  0.0 227768  9972 pts/10   Sl+  17:50   0:00  |           \_ containerd-nslistener
root      1208  0.0  0.0 357528  7832 pts/10   Sl+  17:52   0:00  |           \_ containerd-nslistener
root      1557  0.0  0.0 357176  9872 pts/10   Sl+  17:52   0:00  |           \_ containerd-nslistener
root      2081  0.0  0.0 424632  9892 pts/10   Sl+  17:52   0:00  |           \_ containerd-nslistener
root      4026  0.0  0.0 291640  7872 pts/10   Sl+  17:55   0:00  |           \_ containerd-nslistener
root      4293  0.0  0.0 293304  9900 pts/10   Sl+  17:55   0:00  |           \_ containerd-nslistener
root      4815  0.0  0.0 358840  7692 pts/10   Sl+  17:55   0:00  |           \_ containerd-nslistener
root      5438  0.0  0.0 357432  7680 pts/10   Sl+  17:56   0:00  |           \_ containerd-nslistener
root      5917  0.0  0.0 357176  9852 pts/10   Sl+  17:56   0:00  |           \_ containerd-nslistener
root      6835  0.0  0.0 367036  9964 pts/10   Sl+  17:57   0:00  |           \_ containerd-nslistener
root      7377  0.0  0.0 301244  9888 pts/10   Sl+  17:57   0:00  |           \_ containerd-nslistener
root      7658  0.0  0.0 366780  9816 pts/10   Sl+  17:57   0:00  |           \_ containerd-nslistener
root      8006  0.0  0.0 431164 11872 pts/10   Sl+  17:58   0:00  |           \_ containerd-nslistener
root      8626  0.0  0.0 293560  9860 pts/10   Sl+  17:58   0:00  |           \_ containerd-nslistener
root      9246  0.0  0.0 357432  9872 pts/10   Sl+  17:59   0:00  |           \_ containerd-nslistener
root     10041  0.0  0.0 357176 11828 pts/10   Sl+  17:59   0:00  |           \_ containerd-nslistener
root     10526  0.0  0.0 291896  7816 pts/10   Sl+  17:59   0:00  |           \_ containerd-nslistener
root     10771  0.0  0.0 293304 11808 pts/10   Sl+  17:59   0:00  |           \_ containerd-nslistener

They appear to get created at a rate of 1 per container.

exec failed: No such file or directory

runv commit dbc1d24 upstream.

runv-containerd version 0.01

# uname -a
Linux ubuntu 4.2.0-16-generic #19-Ubuntu SMP Thu Oct 8 15:35:06 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
# cat /etc/issue
Ubuntu 15.10 \n \l
# ./runv-containerd --debug --kernel /var/lib/hyper/kernel --initrd /var/lib/hyper/hyper-initrd.img


# docker run -ti --rm busybox  #ifconfig
exec failed: No such file or directory

Unable to start a container (showing pod timeout) on ubuntu 15.04, qemu version 2.5.50

Output on console for my environment:
abhishek@abhishek-ThinkPad-T450:~/Documents/Works/rootfs$ ls
busybox.tar config.json hyper-initrd.img kernel rootfs runtime.json runv

abhishek@abhishek-ThinkPad-T450:~/Documents/Works/rootfs$ sudo ./runv --kernel kernel --initrd hyper-initrd.img start -v=3

Below is the log:

Log file created at: 2016/04/06 19:04:17
Running on machine: abhishek-ThinkPad-T450
Binary: Built with gc go1.6 for linux/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0406 19:04:16.209307 29345 init_comm.go:72] trying to read 8 bytes
I0406 19:04:17.209827 29345 init_comm.go:83] read 8/8 [length = 0]
I0406 19:04:18.209957 29345 init_comm.go:87] data length is 1482
I0406 19:04:19.210091 29345 init_comm.go:72] trying to read 512 bytes
I0406 19:04:20.210245 29345 init_comm.go:83] read 520/1482 [length = 1482]
I0406 19:04:21.210377 29345 init_comm.go:72] trying to read 512 bytes
I0406 19:04:22.210527 29345 init_comm.go:83] read 1032/1482 [length = 1482]
I0406 19:04:23.210655 29345 init_comm.go:72] trying to read 450 bytes
I0406 19:04:24.210825 29345 init_comm.go:83] read 1482/1482 [length = 1482]
I0406 19:04:25.211448 29345 vm.go:180] hyperHandlePodEvent pod pod-rrYksDEGKS, vm vm-EvCFIREQIF
I0406 19:04:25.211531 29345 hypervisor.go:29] main event loop got message 23(COMMAND_RUN_POD)
I0406 19:04:27.215133 29345 vm_states.go:544] got spec, prepare devices
I0406 19:04:28.217454 29345 vm_states.go:72] initial vm spec: {
"hostname": "shell",
"containers": [],
"shareDir": "share_dir"
}
I0406 19:04:29.217680 29345 context.go:212] VM vm-EvCFIREQIF: state change from INIT to 'STARTING'
I0406 19:04:30.217817 29345 hypervisor.go:29] main event loop got message 11(EVENT_DEV_SKIP)
I0406 19:04:31.217933 29345 vm_states.go:573] device ready, could run pod.
I0406 19:04:25.211638 29345 qemu_process.go:63] cmdline arguments: -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -cpu host -kernel /home/abhishek/Documents/Works/rootfs/kernel -initrd /home/abhishek/Documents/Works/rootfs/hyper-initrd.img -append "console=ttyS0 panic=1 no_timer_check" -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,driftfix=slew -no-reboot -display none -boot strict=on -m 128 -smp 1 -qmp unix:/var/run/hyper/vm-EvCFIREQIF/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-EvCFIREQIF/console.sock,server,nowait -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -chardev socket,id=charch0,path=/var/run/hyper/vm-EvCFIREQIF/hyper.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0 -chardev socket,id=charch1,path=/var/run/hyper/vm-EvCFIREQIF/tty.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1 -fsdev local,id=virtio9p,path=/var/run/hyper/vm-EvCFIREQIF/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir
I0406 19:04:33.225863 29345 qemu_process.go:74] starting daemon with pid: 29390
I0406 19:04:33.246408 29345 tty.go:157] tty socket connected
I0406 19:04:35.228445 29345 tty.go:100] tty: trying to read 12 bytes
I0406 19:04:33.248296 29345 init_comm.go:110] Wating for init messages...
I0406 19:04:37.228709 29345 init_comm.go:72] trying to read 8 bytes
I0406 19:04:33.246453 29345 init_comm.go:29] connected to /var/run/hyper/vm-EvCFIREQIF/console.sock
I0406 19:04:39.232321 29345 init_comm.go:36] connected /var/run/hyper/vm-EvCFIREQIF/console.sock as telnet mode.
I0406 19:04:33.248306 29345 qmp_handler.go:167] connected to /var/run/hyper/vm-EvCFIREQIF/qmp.sock
I0406 19:04:41.235230 29345 qmp_handler.go:177] begin qmp init...
I0406 19:04:42.235415 29345 qmp_handler.go:186] got qmp welcome, now sending command qmp_capabilities
I0406 19:04:43.235614 29345 qmp_handler.go:201] waiting for response
I0406 19:04:40.232705 29345 init_comm.go:44] [console] Initializing cgroup subsys cpu
I0406 19:04:45.235872 29345 init_comm.go:44] [console] Linux version 4.4.0-hyper+ (laijs@ubox) (gcc version 5.2.1 20151010 (Ubuntu 5.2.1-22ubuntu2) ) #0 SMP Mon Jan 25 01:10:46 CST 2016
I0406 19:04:46.236019 29345 init_comm.go:44] [console] Command line: "console=ttyS0 panic=1 no_timer_check"
I0406 19:04:47.236154 29345 init_comm.go:44] [console] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
I0406 19:04:48.236292 29345 init_comm.go:44] [console] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'
I0406 19:04:49.236427 29345 init_comm.go:44] [console] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'
I0406 19:04:50.236555 29345 init_comm.go:44] [console] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'
I0406 19:04:51.236695 29345 init_comm.go:44] [console] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
I0406 19:04:52.236831 29345 init_comm.go:44] [console] x86/fpu: Using 'eager' FPU context switches.
I0406 19:04:53.236965 29345 init_comm.go:44] [console] e820: BIOS-provided physical RAM map:
I0406 19:04:54.237095 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
I0406 19:04:55.237228 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
I0406 19:04:56.237387 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
I0406 19:04:57.237523 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffdfff] usable
I0406 19:04:58.237663 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x0000000007ffe000-0x0000000007ffffff] reserved
I0406 19:04:59.237794 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
I0406 19:05:00.237926 29345 init_comm.go:44] [console] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
I0406 19:05:01.238060 29345 init_comm.go:44] [console] NX (Execute Disable) protection: active
I0406 19:05:02.238194 29345 init_comm.go:44] [console] SMBIOS 2.4 present.
I0406 19:05:03.238328 29345 init_comm.go:44] [console] Hypervisor detected: KVM
I0406 19:05:04.238461 29345 init_comm.go:44] [console] e820: last_pfn = 0x7ffe max_arch_pfn = 0x400000000
I0406 19:05:05.238603 29345 init_comm.go:44] [console] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT
I0406 19:05:06.238737 29345 init_comm.go:44] [console] found SMP MP-table at [mem 0x000f6bd0-0x000f6bdf] mapped at [ffff8800000f6bd0]
I0406 19:05:07.238873 29345 init_comm.go:44] [console] Using GB pages for direct mapping
I0406 19:05:08.239010 29345 init_comm.go:44] [console] RAMDISK: [mem 0x07e58000-0x07feffff]
I0406 19:05:09.239148 29345 init_comm.go:44] [console] ACPI: Early table checksum verification disabled
I0406 19:05:10.239284 29345 init_comm.go:44] [console] ACPI: RSDP 0x00000000000F6A50 000014 (v00 BOCHS )
I0406 19:05:11.239416 29345 init_comm.go:44] [console] ACPI: RSDT 0x0000000007FFF6D8 00002C (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
I0406 19:05:12.239559 29345 init_comm.go:44] [console] ACPI: FACP 0x0000000007FFF5EC 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
I0406 19:05:13.239698 29345 init_comm.go:44] [console] ACPI: DSDT 0x0000000007FFE040 0015AC (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
I0406 19:05:14.239834 29345 init_comm.go:44] [console] ACPI: FACS 0x0000000007FFE000 000040
I0406 19:05:15.240001 29345 init_comm.go:44] [console] ACPI: APIC 0x0000000007FFF660 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
I0406 19:05:16.240139 29345 init_comm.go:44] [console] No NUMA configuration found
I0406 19:05:17.240297 29345 init_comm.go:44] [console] Faking a node at [mem 0x0000000000000000-0x0000000007ffdfff]
I0406 19:05:18.240433 29345 init_comm.go:44] [console] NODE_DATA(0) allocated [mem 0x07e46000-0x07e57fff]
I0406 19:05:19.240825 29345 init_comm.go:44] [console] kvm-clock: Using msrs 4b564d01 and 4b564d00
I0406 19:05:20.240981 29345 init_comm.go:44] [console] kvm-clock: cpu 0, msr 0:7ffd001, primary cpu clock
I0406 19:05:21.241119 29345 init_comm.go:44] [console] kvm-clock: using sched offset of 1238972380 cycles
I0406 19:05:22.241260 29345 init_comm.go:44] [console] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
I0406 19:05:23.241396 29345 init_comm.go:44] [console] Zone ranges:
I0406 19:05:24.241532 29345 init_comm.go:44] [console] DMA [mem 0x0000000000001000-0x0000000000ffffff]
I0406 19:05:25.241691 29345 init_comm.go:44] [console] DMA32 [mem 0x0000000001000000-0x0000000007ffdfff]
I0406 19:05:26.241825 29345 init_comm.go:44] [console] Normal empty
I0406 19:05:27.241960 29345 init_comm.go:44] [console] Movable zone start for each node
I0406 19:05:28.242093 29345 init_comm.go:44] [console] Early memory node ranges
I0406 19:05:29.242232 29345 init_comm.go:44] [console] node 0: [mem 0x0000000000001000-0x000000000009efff]
I0406 19:05:30.242366 29345 init_comm.go:44] [console] node 0: [mem 0x0000000000100000-0x0000000007ffdfff]
I0406 19:05:31.242498 29345 init_comm.go:44] [console] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffdfff]
I0406 19:05:32.242631 29345 init_comm.go:44] [console] ACPI: PM-Timer IO Port: 0x608
I0406 19:05:33.242766 29345 init_comm.go:44] [console] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
I0406 19:05:34.242908 29345 init_comm.go:44] [console] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
I0406 19:05:35.243042 29345 init_comm.go:44] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
I0406 19:05:36.243181 29345 init_comm.go:44] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
I0406 19:05:37.243319 29345 init_comm.go:44] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
I0406 19:05:38.243453 29345 init_comm.go:44] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
I0406 19:05:39.243590 29345 init_comm.go:44] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
I0406 19:05:40.243726 29345 init_comm.go:44] [console] Using ACPI (MADT) for SMP configuration information
I0406 19:05:41.243889 29345 init_comm.go:44] [console] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
I0406 19:05:42.244025 29345 init_comm.go:44] [console] e820: [mem 0x08000000-0xfeffbfff] available for PCI devices
I0406 19:05:43.244162 29345 init_comm.go:44] [console] Booting paravirtualized kernel on KVM
I0406 19:05:44.244298 29345 init_comm.go:44] [console] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
I0406 19:05:45.244442 29345 init_comm.go:44] [console] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_ids:1
I0406 19:05:46.244577 29345 init_comm.go:44] [console] PERCPU: Embedded 31 pages/cpu @ffff880007c00000 s89560 r8192 d29224 u2097152
I0406 19:05:47.244711 29345 init_comm.go:44] [console] KVM setup async PF for cpu 0
I0406 19:05:48.244847 29345 init_comm.go:44] [console] kvm-stealtime: cpu 0, msr 7c0d480
I0406 19:05:49.244979 29345 init_comm.go:44] [console] Built 1 zonelists in Node order, mobility grouping on. Total pages: 32199
I0406 19:05:50.245110 29345 init_comm.go:44] [console] Policy zone: DMA32
I0406 19:05:51.245265 29345 init_comm.go:44] [console] Kernel command line: "console=ttyS0 panic=1 no_timer_check"
I0406 19:05:52.245399 29345 init_comm.go:44] [console] PID hash table entries: 512 (order: 0, 4096 bytes)
I0406 19:05:53.245535 29345 init_comm.go:44] [console] Memory: 119124K/130672K available (4225K kernel code, 452K rwdata, 1280K rodata, 860K init, 752K bss, 11548K reserved, 0K cma-reserved)
I0406 19:05:54.245695 29345 init_comm.go:44] [console] Hierarchical RCU implementation.
I0406 19:05:55.245829 29345 init_comm.go:44] [console] Build-time adjustment of leaf fanout to 64.
I0406 19:05:56.245978 29345 init_comm.go:44] [console] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=1.
I0406 19:05:57.246132 29345 init_comm.go:44] [console] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
I0406 19:05:58.246272 29345 init_comm.go:44] [console] NR_IRQS:4352 nr_irqs:256 16
I0406 19:05:59.246420 29345 init_comm.go:44] [console] Offload RCU callbacks from all CPUs
I0406 19:06:00.246571 29345 init_comm.go:44] [console] Offload RCU callbacks from CPUs: 0.
I0406 19:06:01.246707 29345 init_comm.go:44] [console] Console: colour *CGA 80x25
I0406 19:06:02.246846 29345 init_comm.go:44] [console] console [ttyS0] enabled
I0406 19:06:03.246983 29345 init_comm.go:44] [console] tsc: Detected 2294.688 MHz processor
I0406 19:06:04.247115 29345 init_comm.go:44] [console] Calibrating delay loop (skipped) preset value.. 4589.37 BogoMIPS (lpj=2294688)
I0406 19:06:05.247255 29345 init_comm.go:44] [console] pid_max: default: 32768 minimum: 301
I0406 19:06:06.247396 29345 init_comm.go:44] [console] ACPI: Core revision 20150930
I0406 19:06:07.247532 29345 init_comm.go:44] [console] ACPI: 1 ACPI AML tables successfully acquired and loaded
I0406 19:06:08.247672 29345 init_comm.go:44] [console] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
I0406 19:06:09.247811 29345 init_comm.go:44] [console] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
I0406 19:06:10.247946 29345 init_comm.go:44] [console] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
I0406 19:06:11.248084 29345 init_comm.go:44] [console] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
I0406 19:06:12.248222 29345 init_comm.go:44] [console] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
I0406 19:06:13.248381 29345 init_comm.go:44] [console] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
I0406 19:06:14.248521 29345 init_comm.go:44] [console] Freeing SMP alternatives memory: 20K (ffffffff816ac000 - ffffffff816b1000)
I0406 19:06:15.248659 29345 init_comm.go:44] [console] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
I0406 19:06:16.248792 29345 init_comm.go:44] [console] smpboot: CPU0: Intel(R) Core(TM) i5-5300U CPU @ 2.30GHz (family: 0x6, model: 0x3d, stepping: 0x4)
I0406 19:06:17.248928 29345 init_comm.go:44] [console] Performance Events: 16-deep LBR, Broadwell events, Intel PMU driver.
I0406 19:06:18.249061 29345 init_comm.go:44] [console] ... version: 2
I0406 19:06:19.249380 29345 init_comm.go:44] [console] ... bit width: 48
I0406 19:06:20.249515 29345 init_comm.go:44] [console] ... generic registers: 4
I0406 19:06:21.249648 29345 init_comm.go:44] [console] ... value mask: 0000ffffffffffff
I0406 19:06:22.249781 29345 init_comm.go:44] [console] ... max period: 000000007fffffff
I0406 19:06:23.249925 29345 init_comm.go:44] [console] ... fixed-purpose events: 3
I0406 19:06:24.250069 29345 init_comm.go:44] [console] ... event mask: 000000070000000f
I0406 19:06:25.250228 29345 init_comm.go:44] [console] x86: Booted up 1 node, 1 CPUs
I0406 19:06:26.250362 29345 init_comm.go:44] [console] smpboot: Total of 1 processors activated (4589.37 BogoMIPS)
I0406 19:06:27.250493 29345 init_comm.go:44] [console] devtmpfs: initialized
I0406 19:06:28.250624 29345 init_comm.go:44] [console] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
I0406 19:06:29.250782 29345 init_comm.go:44] [console] NET: Registered protocol family 16
I0406 19:06:30.250883 29345 init_comm.go:44] [console] cpuidle: using governor ladder
I0406 19:06:31.251015 29345 init_comm.go:44] [console] cpuidle: using governor menu
I0406 19:06:32.251149 29345 init_comm.go:44] [console] ACPI: bus type PCI registered
I0406 19:06:33.251290 29345 init_comm.go:44] [console] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
I0406 19:06:34.251427 29345 init_comm.go:44] [console] PCI: Using configuration type 1 for base access
I0406 19:06:35.251557 29345 init_comm.go:44] [console] ACPI: Added _OSI(Module Device)
I0406 19:06:36.251686 29345 init_comm.go:44] [console] ACPI: Added _OSI(Processor Device)
I0406 19:06:37.251821 29345 init_comm.go:44] [console] ACPI: Added _OSI(3.0 _SCP Extensions)
I0406 19:06:38.251937 29345 init_comm.go:44] [console] ACPI: Added _OSI(Processor Aggregator Device)
I0406 19:06:39.252082 29345 init_comm.go:44] [console] ACPI: Interpreter enabled
I0406 19:06:40.252213 29345 init_comm.go:44] [console] ACPI: (supports S0 S5)
I0406 19:06:41.252363 29345 init_comm.go:44] [console] ACPI: Using IOAPIC for interrupt routing
I0406 19:06:42.252508 29345 init_comm.go:44] [console] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
I0406 19:06:43.252638 29345 init_comm.go:44] [console] ACPI: PCI Root Bridge [PCI0](domain 0000 [bus 00-ff])
I0406 19:06:44.252769 29345 init_comm.go:44] [console] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
I0406 19:06:45.252924 29345 init_comm.go:44] [console] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
I0406 19:06:46.253049 29345 init_comm.go:44] [console] acpiphp: Slot [2] registered
I0406 19:06:47.253187 29345 init_comm.go:44] [console] acpiphp: Slot [3] registered
I0406 19:06:48.253319 29345 init_comm.go:44] [console] acpiphp: Slot [4] registered
I0406 19:06:49.253451 29345 init_comm.go:44] [console] acpiphp: Slot [5] registered
I0406 19:06:50.253582 29345 init_comm.go:44] [console] acpiphp: Slot [6] registered
I0406 19:06:51.253727 29345 init_comm.go:44] [console] acpiphp: Slot [7] registered
I0406 19:06:52.253862 29345 init_comm.go:44] [console] acpiphp: Slot [8] registered
I0406 19:06:53.253988 29345 init_comm.go:44] [console] acpiphp: Slot [9] registered
I0406 19:06:54.254121 29345 init_comm.go:44] [console] acpiphp: Slot [10] registered
I0406 19:06:55.254256 29345 init_comm.go:44] [console] acpiphp: Slot [11] registered
I0406 19:06:56.254388 29345 init_comm.go:44] [console] acpiphp: Slot [12] registered
I0406 19:06:57.254520 29345 init_comm.go:44] [console] acpiphp: Slot [13] registered
I0406 19:06:58.254655 29345 init_comm.go:44] [console] acpiphp: Slot [14] registered
I0406 19:06:59.254788 29345 init_comm.go:44] [console] acpiphp: Slot [15] registered
I0406 19:07:00.254924 29345 init_comm.go:44] [console] acpiphp: Slot [16] registered
I0406 19:07:01.255084 29345 init_comm.go:44] [console] acpiphp: Slot [17] registered
I0406 19:07:02.255218 29345 init_comm.go:44] [console] acpiphp: Slot [18] registered
I0406 19:07:03.255347 29345 init_comm.go:44] [console] acpiphp: Slot [19] registered
I0406 19:07:04.255499 29345 init_comm.go:44] [console] acpiphp: Slot [20] registered
I0406 19:07:05.255634 29345 init_comm.go:44] [console] acpiphp: Slot [21] registered
I0406 19:07:06.255766 29345 init_comm.go:44] [console] acpiphp: Slot [22] registered
I0406 19:07:07.255912 29345 init_comm.go:44] [console] acpiphp: Slot [23] registered
I0406 19:07:08.256040 29345 init_comm.go:44] [console] acpiphp: Slot [24] registered
I0406 19:07:09.256167 29345 init_comm.go:44] [console] acpiphp: Slot [25] registered
I0406 19:07:10.256289 29345 init_comm.go:44] [console] acpiphp: Slot [26] registered
I0406 19:07:11.256417 29345 init_comm.go:44] [console] acpiphp: Slot [27] registered
I0406 19:07:12.256542 29345 init_comm.go:44] [console] acpiphp: Slot [28] registered
I0406 19:07:13.256650 29345 init_comm.go:44] [console] acpiphp: Slot [29] registered
I0406 19:07:14.256780 29345 init_comm.go:44] [console] acpiphp: Slot [30] registered
I0406 19:07:15.256856 29345 init_comm.go:44] [console] acpiphp: Slot [31] registered
I0406 19:07:16.256987 29345 init_comm.go:44] [console] PCI host bridge to bus 0000:00
I0406 19:07:17.257132 29345 init_comm.go:44] [console] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
I0406 19:07:18.257272 29345 init_comm.go:44] [console] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
I0406 19:07:19.257404 29345 init_comm.go:44] [console] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
I0406 19:07:20.257536 29345 init_comm.go:44] [console] pci_bus 0000:00: root bus resource [mem 0x08000000-0xfebfffff window]
I0406 19:07:21.257667 29345 init_comm.go:44] [console] pci_bus 0000:00: root bus resource [bus 00-ff]
I0406 19:07:22.257801 29345 init_comm.go:44] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
I0406 19:07:23.257946 29345 init_comm.go:44] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
I0406 19:07:24.258091 29345 init_comm.go:44] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
I0406 19:07:25.258225 29345 init_comm.go:44] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
I0406 19:07:26.258374 29345 init_comm.go:44] [console] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
I0406 19:07:27.258519 29345 init_comm.go:44] [console] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
I0406 19:07:28.258665 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKA](IRQs 5 *10 11)
I0406 19:07:29.258812 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKB](IRQs 5 *10 11)
I0406 19:07:30.258948 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKC](IRQs 5 10 *11)
I0406 19:07:31.259077 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKD](IRQs 5 10 *11)
I0406 19:07:32.259415 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKS](IRQs *9)
I0406 19:07:33.259639 29345 init_comm.go:44] [console] ACPI: Enabled 16 GPEs in block 00 to 0F
I0406 19:07:34.259776 29345 init_comm.go:44] [console] vgaarb: loaded
I0406 19:07:35.259917 29345 init_comm.go:44] [console] SCSI subsystem initialized
I0406 19:07:36.260055 29345 init_comm.go:44] [console] PCI: Using ACPI for IRQ routing
I0406 19:07:37.260206 29345 init_comm.go:44] [console] clocksource: Switched to clocksource kvm-clock
I0406 19:07:38.260340 29345 init_comm.go:44] [console] pnp: PnP ACPI init
I0406 19:07:39.260470 29345 init_comm.go:44] [console] pnp: PnP ACPI: found 5 devices
I0406 19:07:40.260605 29345 init_comm.go:44] [console] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
I0406 19:07:41.260735 29345 init_comm.go:44] [console] NET: Registered protocol family 2
I0406 19:07:42.260865 29345 init_comm.go:44] [console] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
I0406 19:07:43.260994 29345 init_comm.go:44] [console] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
I0406 19:07:44.261125 29345 init_comm.go:44] [console] TCP: Hash tables configured (established 1024 bind 1024)
I0406 19:07:45.261252 29345 init_comm.go:44] [console] UDP hash table entries: 256 (order: 1, 8192 bytes)
I0406 19:07:46.261381 29345 init_comm.go:44] [console] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
I0406 19:07:47.261486 29345 init_comm.go:44] [console] NET: Registered protocol family 1
I0406 19:07:48.261617 29345 init_comm.go:44] [console] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
I0406 19:07:49.261772 29345 init_comm.go:44] [console] pci 0000:00:01.0: PIIX3: Enabling Passive Release
I0406 19:07:50.261899 29345 init_comm.go:44] [console] pci 0000:00:01.0: Activating ISA DMA hang workarounds
I0406 19:07:51.262029 29345 init_comm.go:44] [console] Trying to unpack rootfs image as initramfs...
I0406 19:07:52.262160 29345 init_comm.go:44] [console] Freeing initrd memory: 1632K (ffff880007e58000 - ffff880007ff0000)
I0406 19:07:53.262298 29345 init_comm.go:44] [console] futex hash table entries: 256 (order: 2, 16384 bytes)
I0406 19:07:54.262431 29345 init_comm.go:44] [console] SGI XFS with ACLs, security attributes, no debug enabled
I0406 19:07:55.262570 29345 init_comm.go:44] [console] 9p: Installing v9fs 9p2000 file system support
I0406 19:07:56.262707 29345 init_comm.go:44] [console] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
I0406 19:07:57.262841 29345 init_comm.go:44] [console] io scheduler noop registered
I0406 19:07:58.262975 29345 init_comm.go:44] [console] io scheduler cfq registered (default)
I0406 19:07:59.263111 29345 init_comm.go:44] [console] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
I0406 19:08:00.263243 29345 init_comm.go:44] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
I0406 19:08:01.263366 29345 init_comm.go:44] [console] Warning: Processor Platform Limit event detected, but not handled.
I0406 19:08:02.263502 29345 init_comm.go:44] [console] Consider compiling CPUfreq support into your kernel.
I0406 19:08:03.263629 29345 init_comm.go:44] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x21139aef754, max_idle_ns: 440795211890 ns
I0406 19:08:04.263758 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
I0406 19:08:05.263922 29345 init_comm.go:44] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
I0406 19:08:06.264072 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
I0406 19:08:07.264204 29345 init_comm.go:44] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
I0406 19:08:08.264343 29345 init_comm.go:44] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
I0406 19:08:09.264485 29345 init_comm.go:44] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
I0406 19:08:10.264616 29345 init_comm.go:44] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
I0406 19:08:11.264745 29345 init_comm.go:44] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
I0406 19:08:12.264877 29345 init_comm.go:44] [console] brd: module loaded
I0406 19:08:13.265007 29345 init_comm.go:44] [console] loop: module loaded
I0406 19:08:14.265140 29345 init_comm.go:44] [console] scsi host0: Virtio SCSI HBA
I0406 19:08:15.265269 29345 init_comm.go:44] [console] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
I0406 19:08:16.265398 29345 init_comm.go:44] [console] e1000: Copyright (c) 1999-2006 Intel Corporation.
I0406 19:08:17.265529 29345 init_comm.go:44] [console] NET: Registered protocol family 10
I0406 19:08:18.265657 29345 init_comm.go:44] [console] NET: Registered protocol family 17
I0406 19:08:19.265787 29345 init_comm.go:44] [console] 9pnet: Installing 9P2000 support
I0406 19:08:20.265916 29345 init_comm.go:44] [console] registered taskstats version 1
I0406 19:08:21.266068 29345 init_comm.go:44] [console] Freeing unused kernel memory: 860K (ffffffff815d5000 - ffffffff816ac000)
I0406 19:08:22.266211 29345 init_comm.go:44] [console] create directory /sys
I0406 19:08:23.266340 29345 init_comm.go:44] [console] create directory /proc
I0406 19:08:24.266474 29345 init_comm.go:44] [console] uptime 51.09 0.02
I0406 19:08:25.266619 29345 init_comm.go:44] [console]
I0406 19:08:26.266834 29345 init_comm.go:44] [console] create directory /dev/pts
I0406 19:08:27.266972 29345 init_comm.go:44] [console] open hyper channel /dev/vport0p1
I0406 19:08:28.267105 29345 init_comm.go:44] [console] send ready message
I0406 19:08:29.267391 29345 init_comm.go:44] [console] hyper send type 8, len 0
I0406 19:08:30.267475 29345 init_comm.go:44] [console] channel sh.hyper.channel.1, directory sh.hyper.channel.0
I0406 19:08:31.267612 29345 init_comm.go:44] [console]
I0406 19:08:32.267896 29345 init_comm.go:44] [console] open hyper channel /dev/vport0p2
I0406 19:08:33.268309 29345 init_comm.go:44] [console] hyper_init_event hyper channel event 0x614580, ops 0x614380, fd 3
I0406 19:08:34.268487 29345 init_comm.go:44] [console] hyper_add_event add event fd 3, 0x614380
I0406 19:08:35.268619 29345 init_comm.go:44] [console] hyper_init_event hyper ttyfd event 0x614548, ops 0x614340, fd 4
I0406 19:08:36.268761 29345 init_comm.go:44] [console] hyper_add_event add event fd 4, 0x614340
I0406 19:06:07.256048 29345 init_comm.go:83] read 8/8 [length = 0]
I0406 19:08:38.286252 29345 init_comm.go:87] data length is 8
I0406 19:08:39.286393 29345 init_comm.go:120] Get init ready message
I0406 19:08:40.286551 29345 init_comm.go:164] got cmd:1
I0406 19:08:41.286730 29345 init_comm.go:245] send command 1 to init, payload: '{"hostname":"shell","containers":[],"shareDir":"share_dir"}'.
I0406 19:08:42.286881 29345 init_comm.go:258] write 67 to init, payload: '\00\00\00�\00\00\00C{"hostname":"shell","containers":[],"shareDir":"share_dir"}'.
I0406 19:08:43.287019 29345 init_comm.go:263] message sent, set pong timer
W0406 19:05:25.211686 29345 qmp_handler.go:282] Initializer Timeout.
E0406 19:08:45.292385 29345 qmp_handler.go:368] QMP initialize timeout
I0406 19:05:01.242258 29345 qmp_handler.go:103] got a message {"return": {}}
I0406 19:08:47.315364 29345 qmp_handler.go:210] got for response
I0406 19:08:48.315499 29345 qmp_handler.go:213] QMP connection initialized
I0406 19:05:29.217795 29345 hypervisor.go:29] main event loop got message 3(EVENT_VM_TIMEOUT)
E0406 19:08:50.318243 29345 vm_states.go:346] Shutting down because of an exception: Start POD timeout
I0406 19:08:51.318381 29345 context.go:212] VM vm-EvCFIREQIF: state change from STARTING to 'TERMINATING'
E0406 19:08:52.318518 29345 vm_states.go:629] Start POD timeout
I0406 19:08:53.319523 29345 hypervisor.go:29] main event loop got message 5(EVENT_INIT_CONNECTED)
W0406 19:08:54.319661 29345 vm_states.go:482] got unexpected event during terminating
I0406 19:08:55.319797 29345 hypervisor.go:29] main event loop got message 41(ERROR_INIT_FAIL)
W0406 19:08:56.319934 29345 vm_states.go:482] got unexpected event during terminating
I0406 19:08:40.286582 29345 init_comm.go:72] trying to read 8 bytes
I0406 19:08:58.338739 29345 init_comm.go:83] read 8/8 [length = 0]
I0406 19:08:59.338912 29345 init_comm.go:87] data length is 12
I0406 19:09:00.339045 29345 init_comm.go:72] trying to read 4 bytes
I0406 19:09:01.339187 29345 init_comm.go:83] read 12/12 [length = 12]
I0406 19:09:02.339321 29345 init_comm.go:72] trying to read 8 bytes
I0406 19:09:03.339466 29345 init_comm.go:83] read 8/8 [length = 0]
I0406 19:09:04.339601 29345 init_comm.go:87] data length is 12
I0406 19:09:05.339733 29345 init_comm.go:72] trying to read 4 bytes
I0406 19:09:06.339886 29345 init_comm.go:83] read 12/12 [length = 12]
I0406 19:09:07.340023 29345 init_comm.go:72] trying to read 8 bytes
I0406 19:09:08.340164 29345 init_comm.go:83] read 8/8 [length = 0]
I0406 19:09:09.340294 29345 init_comm.go:87] data length is 8
I0406 19:09:10.340442 29345 init_comm.go:72] trying to read 8 bytes

Unable to start container on Fedora 22

I'm unable to start a container using runv and qemu on my Fedora 22 system.
The busybox container rootfs along with config.json and runtime.json is in the current dir.
The qemu instance does get created. Any suggestions on debugging the issue ?

# ./runv --kernel ../hyperstart/build/kernel --initrd ../hyperstart/build/hyper-initrd.img start start
tag=qck14w9g
Failed to reset winsize
copy from stdin to remote 0, err write unix @->/run/opencontainer/containers/runv/runv.sock: write: broken pipe
runvRequest failed: dial unix /run/opencontainer/containers/runv/runv.sock: connect: connection refused
start container failed: dial unix /run/opencontainer/containers/runv/runv.sock: connect: connection refused

# ps aux | grep qemu
root     21259 96.0  1.1 793620 93744 ?        Sl   11:41   0:03 qemu-system-x86_64 -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -cpu host -kernel /home/pradipta/temp/hyperstart/build/kernel -initrd /home/pradipta/temp/hyperstart/build/hyper-initrd.img -append "console=ttyS0 panic=1 no_timer_check" -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,driftfix=slew -no-reboot -display none -boot strict=on -m 128 -smp 1 -qmp unix:/var/run/hyper/vm-MjoAidCDJo/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-MjoAidCDJo/console.sock,server,nowait -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x3 -chardev socket,id=charch0,path=/var/run/hyper/vm-MjoAidCDJo/hyper.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0 -chardev socket,id=charch1,path=/var/run/hyper/vm-MjoAidCDJo/tty.sock,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1 -fsdev local,id=virtio9p,path=/var/run/hyper/vm-MjoAidCDJo/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir

check dns items, they should be IPs

we shouldn't allow such pod config:
{
...
"dns": ["dns-what-the-fuck"],
...
}

move the code of api between runv and hyperstart into hyperstart/api/json/

the code of api between runv and hyperstart is spread everywhere

hypervisor/constants.go INIT_XXXX
hypervisor/events.go the structs sent into hyperstart
ttyMessage
WindowSize
(all structs sent into ctx.vm)
hypervisor/pod.go the structs VmXXXX
others ...

after they are moved, they will be referred via hyperstartapi.XXXXX

import hyperstartapi "github.com/hyperhq/runv/hyperstart/api/json"

@YaoZengzeng

You must have autoconf installed to generate the hyper.

Let's create some additional documentation for build dependencies.

Otherwise people will see things like this:

You must have autoconf installed to generate the hyper.
You must have automake installed to generate the hyper.
You must have autoreconf installed to generate the hyper.

use virtio-vsock to communicate with hyperstart

virtio-vsock (http://qemu-project.org/Features/VirtioVsock) was introduced as a communication device between host and guest. runv and hyperstart can use it to replace current serial port communication method.

runv-containerd not working on Ubuntu or Fedora

Unfortunately spawning a VM via runv-containerd doesn't seem to work. I tried both on Ubuntu and Fedora.
It fails to initialize QMP

4986 qmp_handler.go:181] get qmp welcome failed:

Here are the debug logs - http://pastebin.com/UHsXLpis

Impact of --solo-namespaced ?

I'm trying to get a feel for what the parameter --solo-namespaced actually implements when running runv containerd.

My impression from the code is that it shares events between containers started in separate VMs? But what is the benefit of doing this.

The context of the question is I'm trying to figure out if its possible at the moment for containers to share network namespace sensibly when runv is used with docker as a containerd backend. I don't get any errors, but it also doesn't seem to work.

How can I try this ?

I have big interest on this project.
But I cant try it : (

Is there any prerequisites ?
I built runv version 0.6.0

$ sudo runv --initrd=/var/lib/hyper/hyper-initrd.img start test error rpc error: code = 2 desc = empty bundle path

add `runv delete` sub command

and other commands that runc has.

Rbd volume not working for libvirt driver

Currently, runv generates spec for rbd volue as follows:

<disk type="file" device="disk"><driver><Type>rbd</Type></driver><source file="rbd:test/rbd-image"></source><target dev="sdc" bus="scsi"></target><address type="drive" controller="0" bus="0" unit="2"></address></disk>

While the correct rbd volume spec for rbd volume is

<disk type='network' device='disk'>
        <source protocol='rbd' name='libvirt-pool/new-libvirt-image'>
                <host name='{monitor-host}' port='6789'/>
        </source>
        <auth username='libvirt'>
                <secret type='ceph' uuid='9ec59067-fdbc-a6c0-03ff-df165c0587b8'/>
        </auth>
        <target dev='vda' bus='virtio'/>
</disk>

Ref http://docs.ceph.com/docs/master/rbd/libvirt/

Compile failed on darwin

lei@leis-MacBook-Pro:[runv] (lazymode_portmap)$ make
godep go build -tags "static_build " runv.go runv_darwin.go
# github.com/hyperhq/runv/hypervisor
hypervisor/hypervisor.go:111: too many arguments in call to network.InitNetwork
godep: go exit status 2
make: *** [build-runv] Error 1
lei@leis-MacBook-Pro:[runv] (lazymode_portmap)$ uname -a
Darwin localhost 14.5.0 Darwin Kernel Version 14.5.0: Wed Jul 29 02:26:53 PDT 2015; root:xnu-2782.40.9~1/RELEASE_X86_64 x86_64
lei@leis-MacBook-Pro:[runv] (lazymode_portmap)$