· 10 years ago · Sep 22, 2016, 06:58 AM
1[root@localhost hyperd]# ./hyperd -v 3
2I0922 14:36:39.856681 6395 hyperd.go:106] The config file is
3I0922 14:36:39.861180 6395 daemon.go:141] The config: kernel=/var/lib/hyper/kernel, initrd=/var/lib/hyper/hyper-initrd.img
4I0922 14:36:39.861416 6395 daemon.go:143] The config: vbox image=
5I0922 14:36:39.861598 6395 daemon.go:146] The config: bridge=, ip=
6I0922 14:36:39.861745 6395 daemon.go:149] The config: bios=, cbfs=
7DEBU[0000] Using default logging driver none
8DEBU[0000] devicemapper: driver version is 4.34.0
9DEBU[0000] devmapper: Generated prefix: docker-253:0-1573769
10DEBU[0000] devmapper: Checking for existence of the pool docker-253:0-1573769-pool
11DEBU[0000] devmapper: Pool doesn't exist. Creating it.
12DEBU[0000] devmapper: loadDeviceFilesOnStart()
13DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/831deeebf58f19fa49f3be37dc6ded131b5dfb8e552869ffc53694e9984b0131
14DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/a980b8a088852a01f42768b3906ada30b1ecad14c8ce765a4c9cb524a4eef2c8
15DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/base
16DEBU[0000] devmapper: Skipping file /var/lib/hyper/devicemapper/metadata/deviceset-metadata
17DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/e11ca2da1939fcc8b5148ed32315a0d63ad9aa28afb4bd6dda56fa4a045f0bd8
18DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/e139596f77e84ef2b9ac71cee2b5d29bb2e2a25b8de8032a8049893f68730f68
19DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/f3ea03622be802c772076a261c5d0230a6de98945b1c96e786fa2d6fb0accef4
20DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/fb285e71b164736d7a0d190d444fcc72310fd93b1d630eb33cf89b5f3c530a7c
21DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/fb285e71b164736d7a0d190d444fcc72310fd93b1d630eb33cf89b5f3c530a7c-init
22DEBU[0000] devmapper: Skipping file /var/lib/hyper/devicemapper/metadata/transaction-metadata
23DEBU[0000] devmapper: loadDeviceFilesOnStart() END
24DEBU[0000] devmapper: constructDeviceIDMap()
25DEBU[0000] devmapper: Added deviceId=2 to DeviceIdMap
26DEBU[0000] devmapper: Added deviceId=3 to DeviceIdMap
27DEBU[0000] devmapper: Added deviceId=6 to DeviceIdMap
28DEBU[0000] devmapper: Added deviceId=8 to DeviceIdMap
29DEBU[0000] devmapper: Added deviceId=7 to DeviceIdMap
30DEBU[0000] devmapper: Added deviceId=4 to DeviceIdMap
31DEBU[0000] devmapper: Added deviceId=5 to DeviceIdMap
32DEBU[0000] devmapper: Added deviceId=1 to DeviceIdMap
33DEBU[0000] devmapper: constructDeviceIDMap() END
34WARN[0000] devmapper: Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or use `man docker` to refer to dm.thinpooldev section.
35DEBU[0000] devmapper: activateDeviceIfNeeded()
36DEBU[0000] devmapper: UUID for device: /dev/mapper/docker-253:0-1573769-base is:a44e9b20-dacd-4ace-9d86-2cbef0cf7f73
37WARN[0000] devmapper: Base device already exists and has filesystem xfs on it. User specified filesystem will be ignored.
38DEBU[0000] devmapper: deactivateDevice()
39DEBU[0000] devmapper: removeDevice START(docker-253:0-1573769-base)
40DEBU[0000] devmapper: removeDevice END(docker-253:0-1573769-base)
41DEBU[0000] devmapper: deactivateDevice END()
42INFO[0000] [graphdriver] using prior storage driver "devicemapper"
43DEBU[0000] Using graph driver devicemapper
44INFO[0000] Graph migration to content-addressability took 0.00 seconds
45DEBU[0000] Option DefaultDriver: bridge
46DEBU[0000] Option DefaultNetwork: bridge
47INFO[0000] Firewalld running: false
48DEBU[0000] Registering ipam driver: "default"
49DEBU[0000] Cleaning up old shm/mqueue mounts: start.
50DEBU[0000] Cleaning up old shm/mqueue mounts: done.
51DEBU[0000] Loaded container 095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558
52I0922 14:36:40.674497 6395 server.go:70] Server created for HTTP on unix (/var/run/hyper.sock)
53Qemu Driver Loaded
54I0922 14:36:40.674683 6395 hyperd.go:193] The hypervisor's driver is qemu
55I0922 14:36:40.677319 6395 network_linux.go:246] create bridge hyper0, ip 192.168.123.0/24
56I0922 14:36:40.677987 6395 network_linux.go:367] Allocate IP Address 192.168.123.1 for bridge hyper0
57I0922 14:36:40.678012 6395 network_linux.go:518] ifaddmsg length 8
58I0922 14:36:40.681923 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -C POSTROUTING -s 192.168.123.1/24 ! -o hyper0 -j MASQUERADE]
59I0922 14:36:40.697763 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -I POSTROUTING -s 192.168.123.1/24 ! -o hyper0 -j MASQUERADE]
60I0922 14:36:40.703939 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -N HYPER]
61I0922 14:36:40.712908 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o hyper0 -j HYPER]
62I0922 14:36:40.724293 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -I FORWARD -o hyper0 -j HYPER]
63I0922 14:36:40.731240 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i hyper0 -j ACCEPT]
64I0922 14:36:40.738112 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -I FORWARD -i hyper0 -j ACCEPT]
65I0922 14:36:40.742164 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o hyper0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]
66I0922 14:36:40.750254 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -I FORWARD -o hyper0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]
67I0922 14:36:40.755145 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -N HYPER]
68I0922 14:36:40.757798 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL ! -d 127.0.0.1/8 -j HYPER]
69I0922 14:36:40.775076 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -I OUTPUT -m addrtype --dst-type LOCAL ! -d 127.0.0.1/8 -j HYPER]
70I0922 14:36:40.776738 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j HYPER]
71I0922 14:36:40.781011 6395 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -I PREROUTING -m addrtype --dst-type LOCAL -j HYPER]
72I0922 14:36:40.783717 6395 daemondb.go:220] got key from leveldb pod-container-pod-hzAvAkahvf
73I0922 14:36:40.783750 6395 daemondb.go:220] got key from leveldb pod-pod-hzAvAkahvf
74I0922 14:36:40.783769 6395 daemon.go:85] reloading pod pod-hzAvAkahvf with args {"id":"ubuntu-8437595367","hostname":"","containers":[{"name":"ubuntu-8437595367","image":"ubuntu","user":{"name":"","group":""},"command":[],"workdir":"/","entrypoint":[],"tty":true,"labels":null,"ports":null,"envs":null,"volumes":[{"path":"/etc/hosts","volume":"etchosts-volume","readOnly":false}],"files":[{"path":"/etc/resolv.conf","filename":"pod-hzAvAkahvf-resolvconf","perm":"0644","user":"","group":""}],"restartPolicy":"never"}],"resource":{"vcpu":1,"memory":128},"files":[{"name":"pod-hzAvAkahvf-resolvconf","encoding":"raw","uri":"file:///etc/resolv.conf","content":""}],"volumes":[{"name":"etchosts-volume","source":"/var/lib/hyper/hosts/pod-hzAvAkahvf/hosts","driver":"vfs","option":{"monitors":null,"user":"","keyring":"","bytespersec":0,"iops":0}}],"labels":{"extra.sh.hyper.container.0.initialize":"yes"},"log":{"type":"","config":{}},"tty":true,"type":"","RestartPolicy":""}
75I0922 14:36:40.784313 6395 run.go:40] podArgs: id:"ubuntu-8437595367" tty:true labels:<key:"extra.sh.hyper.container.0.initialize" value:"yes" > resource:<vcpu:1 memory:128 > log:<> containers:<name:"ubuntu-8437595367" image:"ubuntu" workdir:"/" restartPolicy:"never" tty:true volumes:<path:"/etc/hosts" volume:"etchosts-volume" > files:<path:"/etc/resolv.conf" filename:"pod-hzAvAkahvf-resolvconf" perm:"0644" > user:<> > files:<name:"pod-hzAvAkahvf-resolvconf" encoding:"raw" uri:"file:///etc/resolv.conf" > volumes:<name:"etchosts-volume" source:"/var/lib/hyper/hosts/pod-hzAvAkahvf/hosts" driver:"vfs" option:<> >
76I0922 14:36:40.784548 6395 pod.go:905] Already has resolv.conf configured, bypass DNS insert
77I0922 14:36:40.784629 6395 daemondb.go:82] try get container list for pod pod-hzAvAkahvf
78I0922 14:36:40.784653 6395 pod.go:467] loaded containers for pod pod-hzAvAkahvf: [095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558]
79I0922 14:36:40.784783 6395 pod.go:475] Loading container 095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558 of pod pod-hzAvAkahvf
80I0922 14:36:40.784854 6395 pod.go:487] Found exist container ubuntu-8437595367 (095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558), pod: pod-hzAvAkahvf
81I0922 14:36:40.784863 6395 pod.go:520] do not need to create container ubuntu-8437595367 of pod pod-hzAvAkahvf[0]
82I0922 14:36:40.784871 6395 pod.go:597] container name ubuntu-8437595367, image ubuntu
83I0922 14:36:40.785003 6395 pod.go:624] container info config &{095fb3829af8 false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc820640280 false ubuntu map[] <nil> true [] map[] }, Cmd [/bin/bash], Args []
84I0922 14:36:40.785109 6395 pod.go:648] Container Info is
85&{containerID:"095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558" commands:"/bin/bash" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474356725 fb285e71b164736d7a0d190d444fcc72310fd93b1d630eb33cf89b5f3c530a7c true}
86I0922 14:36:40.785308 6395 daemondb.go:91] try set container list for pod pod-hzAvAkahvf: [095fb3829af8bb705ac5c5019ea33f574f2a47caf2d0ee2e9702103e107c8558]
87I0922 14:36:40.785433 6395 daemon.go:109] no existing VM for pod pod-hzAvAkahvf: leveldb: not found
88I0922 14:36:40.785500 6395 daemon.go:119] 1 pod have been loaded
89I0922 14:36:40.785509 6395 daemon.go:121] container in pod pod-hzAvAkahvf status: [0xc820188870]
90I0922 14:36:40.785517 6395 daemon.go:122] container in pod pod-hzAvAkahvf spec: [{ubuntu-8437595367 ubuntu { []} [] / [] true map[] map[] [] [] [{/etc/hosts etchosts-volume false}] [{/etc/resolv.conf pod-hzAvAkahvf-resolvconf 0644 }] never}]
91I0922 14:36:40.785956 6395 server.go:199] Registering routers
92I0922 14:36:40.785971 6395 server.go:204] Registering GET, /container/info
93I0922 14:36:40.786189 6395 server.go:204] Registering GET, /container/logs
94I0922 14:36:40.786352 6395 server.go:204] Registering GET, /exitcode
95I0922 14:36:40.786466 6395 hyperd.go:245] Hyper daemon: 0.6.2 0
96I0922 14:36:40.786513 6395 server.go:204] Registering POST, /container/create
97I0922 14:36:40.786637 6395 server.go:204] Registering POST, /container/rename
98I0922 14:36:40.786788 6395 server.go:204] Registering POST, /container/commit
99I0922 14:36:40.786958 6395 server.go:204] Registering POST, /container/stop
100I0922 14:36:40.787228 6395 server.go:204] Registering POST, /container/kill
101I0922 14:36:40.787414 6395 server.go:204] Registering POST, /exec/create
102I0922 14:36:40.787570 6395 server.go:204] Registering POST, /exec/start
103I0922 14:36:40.787702 6395 server.go:204] Registering POST, /attach
104I0922 14:36:40.787854 6395 server.go:204] Registering POST, /tty/resize
105I0922 14:36:40.787985 6395 server.go:204] Registering GET, /pod/info
106I0922 14:36:40.788150 6395 server.go:204] Registering GET, /pod/stats
107I0922 14:36:40.788288 6395 server.go:204] Registering GET, /list
108I0922 14:36:40.788398 6395 server.go:204] Registering POST, /pod/create
109I0922 14:36:40.788521 6395 server.go:204] Registering POST, /pod/labels
110I0922 14:36:40.788653 6395 server.go:204] Registering POST, /pod/start
111I0922 14:36:40.788791 6395 server.go:204] Registering POST, /pod/stop
112I0922 14:36:40.788938 6395 server.go:204] Registering POST, /pod/kill
113I0922 14:36:40.789097 6395 server.go:204] Registering POST, /pod/pause
114I0922 14:36:40.789249 6395 server.go:204] Registering POST, /pod/unpause
115I0922 14:36:40.789865 6395 server.go:204] Registering POST, /vm/create
116I0922 14:36:40.790118 6395 server.go:204] Registering DELETE, /pod
117I0922 14:36:40.790329 6395 server.go:204] Registering DELETE, /vm
118I0922 14:36:40.790517 6395 server.go:204] Registering GET, /service/list
119I0922 14:36:40.790712 6395 server.go:204] Registering POST, /service/add
120I0922 14:36:40.790899 6395 server.go:204] Registering POST, /service/update
121I0922 14:36:40.791046 6395 server.go:204] Registering DELETE, /service
122I0922 14:36:40.791186 6395 server.go:204] Registering GET, /images/get
123I0922 14:36:40.791344 6395 server.go:204] Registering POST, /image/create
124I0922 14:36:40.791492 6395 server.go:204] Registering POST, /image/load
125I0922 14:36:40.791655 6395 server.go:204] Registering POST, /image/push
126I0922 14:36:40.791803 6395 server.go:204] Registering DELETE, /image
127I0922 14:36:40.791951 6395 server.go:204] Registering GET, /_ping
128I0922 14:36:40.791998 6395 server.go:204] Registering GET, /info
129I0922 14:36:40.792209 6395 server.go:204] Registering GET, /version
130I0922 14:36:40.792371 6395 server.go:204] Registering POST, /auth
131I0922 14:36:40.792490 6395 server.go:204] Registering POST, /image/build
132I0922 14:36:40.792660 6395 server.go:95] API listen on /var/run/hyper.sock
133I0922 14:37:03.992291 6395 server.go:152] Calling GET /v0.6.2/list
134I0922 14:37:03.992403 6395 pod_routes.go:52] List type is pod, specified pod: [], specified vm: [], list auxiliary pod: false
135I0922 14:37:24.921829 6395 server.go:152] Calling POST /v0.6.2/image/create
136DEBU[0045] Trying to pull busybox from https://registry-1.docker.io v2
137DEBU[0047] Increasing token expiration to: 0 seconds
138DEBU[0048] Pulling ref from V2 registry: busybox:latest
139DEBU[0048] pulling blob "sha256:8ddc19f16526912237dd8af81971d5e4dd0587907234be2b83e249518d5b673f"
140DEBU[0050] Downloaded 8ddc19f16526 to tempfile /var/lib/hyper/tmp/GetImageBlob260350365
141DEBU[0050] devmapper: AddDevice(hash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15 basehash=)
142DEBU[0050] devmapper: registerDevice(9, 59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
143DEBU[0050] devmapper: AddDevice(hash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15 basehash=) END
144DEBU[0050] devmapper: activateDeviceIfNeeded(59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
145DEBU[0050] Start untar layer
146DEBU[0050] Untar time: 0.117029403s
147DEBU[0050] devmapper: UnmountDevice(hash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
148DEBU[0050] devmapper: Unmount(/var/lib/hyper/devicemapper/mnt/59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
149DEBU[0050] devmapper: Unmount done
150DEBU[0050] devmapper: deactivateDevice(59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
151DEBU[0050] devmapper: removeDevice START(docker-253:0-1573769-59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
152DEBU[0050] devmapper: removeDevice END(docker-253:0-1573769-59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
153DEBU[0050] devmapper: deactivateDevice END(59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
154DEBU[0050] devmapper: UnmountDevice(hash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15) END
155DEBU[0050] Applied tar sha256:8ac8bfaff55af948c796026ee867448c5b5b5d9dd3549f4006d9759b25d4a893 to 59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15, size: 1092588
156I0922 14:37:53.137487 6395 server.go:152] Calling POST /v0.6.2/vm/create
157I0922 14:37:53.137614 6395 vm.go:192] The config: kernel=/var/lib/hyper/kernel, initrd=/var/lib/hyper/hyper-initrd.img
158I0922 14:37:53.138533 6395 server.go:152] Calling POST /v0.6.2/pod/create
159I0922 14:37:53.138606 6395 pod_routes.go:76] Args string is {"id":"busybox-8924984816","hostname":"","containers":[{"name":"busybox-8924984816","image":"busybox","user":{"name":"","group":""},"command":[],"workdir":"/","entrypoint":[],"labels":null,"ports":[],"envs":[],"volumes":[],"files":[],"restartPolicy":"never"}],"resource":{"vcpu":1,"memory":128},"files":[],"volumes":[],"labels":{},"log":{"type":"","config":{}},"tty":true,"type":"","RestartPolicy":""}, autoremove false
160I0922 14:37:53.138967 6395 run.go:40] podArgs: id:"busybox-8924984816" tty:true resource:<vcpu:1 memory:128 > log:<> containers:<name:"busybox-8924984816" image:"busybox" workdir:"/" restartPolicy:"never" user:<> >
161I0922 14:37:53.140756 6395 qemu_amd64.go:44] kvm not exist change to no kvm mode
162I0922 14:37:53.140925 6395 qemu_process.go:130] cmdline arguments: -machine pc-i440fx-2.0,usb=off -cpu core2duo -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-OmUeiQBIAF/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-OmUeiQBIAF/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-OmUeiQBIAF/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-OmUeiQBIAF/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-OmUeiQBIAF/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir
163I0922 14:37:53.144835 6395 daemondb.go:82] try get container list for pod pod-htusddiFbu
164I0922 14:37:53.144914 6395 pod.go:467] loaded containers for pod pod-htusddiFbu: []
165DEBU[0073] devmapper: AddDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init basehash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
166DEBU[0073] devmapper: registerDevice(10, c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
167DEBU[0073] devmapper: AddDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init basehash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15) END
168DEBU[0073] devmapper: activateDeviceIfNeeded(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
169DEBU[0073] devmapper: UnmountDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
170DEBU[0073] devmapper: Unmount(/var/lib/hyper/devicemapper/mnt/c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
171DEBU[0073] devmapper: Unmount done
172DEBU[0073] devmapper: deactivateDevice(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
173DEBU[0073] devmapper: removeDevice START(docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
174DEBU[0073] devmapper: removeDevice END(docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
175DEBU[0073] devmapper: deactivateDevice END(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
176DEBU[0073] devmapper: UnmountDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init) END
177DEBU[0073] devmapper: AddDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d basehash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init)
178DEBU[0073] devmapper: registerDevice(11, c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
179DEBU[0073] devmapper: AddDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d basehash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d-init) END
180DEBU[0073] devmapper: activateDeviceIfNeeded(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
181DEBU[0073] container mounted via layerStore: /var/lib/hyper/devicemapper/mnt/c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d/rootfs
182DEBU[0073] devmapper: UnmountDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
183DEBU[0073] devmapper: Unmount(/var/lib/hyper/devicemapper/mnt/c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
184DEBU[0073] devmapper: Unmount done
185DEBU[0073] devmapper: deactivateDevice(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
186DEBU[0073] devmapper: removeDevice START(docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
187I0922 14:37:53.315652 6395 init_comm.go:142] Wating for init messages...
188I0922 14:37:53.316403 6395 init_comm.go:96] trying to read 8 bytes
189I0922 14:37:53.317571 6395 qmp_handler.go:167] connected to /var/run/hyper/vm-OmUeiQBIAF/qmp.sock
190I0922 14:37:53.319679 6395 qmp_handler.go:177] begin qmp init...
191I0922 14:37:53.317700 6395 tty.go:146] tty socket connected
192I0922 14:37:53.317675 6395 init_comm.go:53] connected to /var/run/hyper/vm-OmUeiQBIAF/console.sock
193I0922 14:37:53.323210 6395 init_comm.go:60] connected /var/run/hyper/vm-OmUeiQBIAF/console.sock as telnet mode.
194I0922 14:37:53.323181 6395 tty.go:89] tty: trying to read 12 bytes
195DEBU[0073] devmapper: removeDevice END(docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
196DEBU[0073] devmapper: deactivateDevice END(c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d)
197DEBU[0073] devmapper: UnmountDevice(hash=c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d) END
198I0922 14:37:53.336281 6395 pod.go:557] create container 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d
199I0922 14:37:53.336495 6395 pod.go:597] container name busybox-8924984816, image busybox
200I0922 14:37:53.336776 6395 pod.go:624] container info config &{4c09260a5316 false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc821443d00 false busybox map[] <nil> true [] map[] }, Cmd [sh], Args []
201I0922 14:37:53.337079 6395 pod.go:648] Container Info is
202&{containerID:"4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d" commands:"sh" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474526273 c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d true}
203I0922 14:37:53.337983 6395 daemondb.go:91] try set container list for pod pod-htusddiFbu: [4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d]
204I0922 14:37:53.338675 6395 server.go:152] Calling GET /v0.6.2/pod/info
205I0922 14:37:53.340652 6395 server.go:152] Calling POST /v1.17/pod/start
206I0922 14:37:53.340998 6395 run.go:68] Run pod with tty attached
207I0922 14:37:53.341352 6395 run.go:76] pod:pod-htusddiFbu, vm:vm-OmUeiQBIAF
208I0922 14:37:53.341722 6395 pod.go:320] lock pod pod-htusddiFbu for operation start
209I0922 14:37:53.341945 6395 pod.go:323] successfully lock pod pod-htusddiFbu for operation start
210I0922 14:37:53.342135 6395 vm.go:229] find vm:vm-OmUeiQBIAF
211I0922 14:37:53.342356 6395 pod.go:960] container ID: 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d, mountId c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d
212I0922 14:37:53.376274 6395 dm.go:95] The filesytem type is xfs
213I0922 14:37:53.381156 6395 qmp_handler.go:186] got qmp welcome, now sending command qmp_capabilities
214I0922 14:37:53.381206 6395 qmp_handler.go:201] waiting for response
215I0922 14:37:53.386153 6395 qemu_process.go:204] starting daemon with pid: 6678
216I0922 14:37:53.386277 6395 qmp_handler.go:103] got a message {"return": {}}
217I0922 14:37:53.386314 6395 qmp_handler.go:210] got for response
218I0922 14:37:53.386319 6395 qmp_handler.go:213] QMP connection initialized
219I0922 14:37:53.386338 6395 qmp_handler.go:346] QMP initialzed, go into main QMP loop
220I0922 14:37:53.386347 6395 qmp_handler.go:137] Begin receive QMP message
221I0922 14:37:53.406083 6395 volumes.go:29] trying to bind dir /var/lib/hyper/hosts/pod-htusddiFbu/hosts to /var/run/hyper/vm-OmUeiQBIAF/share_dir/vzlFZkbYaZ
222I0922 14:37:53.406224 6395 storage.go:79] dir /var/lib/hyper/hosts/pod-htusddiFbu/hosts is bound to vzlFZkbYaZ
223I0922 14:37:53.406244 6395 pod.go:1119] configuring log driver [json-file] for pod-htusddiFbu
224I0922 14:37:53.406294 6395 pod.go:1147] configure container log to /var/run/hyper/Pods/pod-htusddiFbu/4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d-json.log
225I0922 14:37:53.406328 6395 pod.go:1153] configured logger for pod-htusddiFbu/4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d (/busybox-8924984816)
226I0922 14:37:53.406363 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 34(GENERIC_OPERATION)
227I0922 14:37:53.406370 6395 vm_states.go:296] handle GenericOperation(Attach) on state(INIT)
228I0922 14:37:53.406396 6395 vm_states.go:229] attachment 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d is pending
229I0922 14:37:53.406410 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 34(GENERIC_OPERATION)
230I0922 14:37:53.406413 6395 vm_states.go:296] handle GenericOperation(Attach) on state(INIT)
231I0922 14:37:53.406416 6395 vm_states.go:229] attachment 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d is pending
232I0922 14:37:53.406420 6395 pod.go:1205] Attach to container 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d before start pod
233I0922 14:37:53.406440 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 21(COMMAND_RUN_POD)
234I0922 14:37:53.406444 6395 vm_states.go:443] got spec, prepare devices
235I0922 14:37:53.406454 6395 context.go:292] #0 Container Info:
236I0922 14:37:53.406569 6395 vm.go:162] hyperHandlePodEvent pod pod-htusddiFbu, vm vm-OmUeiQBIAF
237I0922 14:37:53.406617 6395 context.go:295]
238{
239...| "Id": "4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d",
240...| "User": "",
241...| "MountId": "c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d",
242...| "Rootfs": "/rootfs",
243...| "Image": {
244...| "name": "",
245...| "source": "/dev/mapper/docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d",
246...| "driver": "",
247...| "option": {
248...| "monitors": null,
249...| "user": "",
250...| "keyring": "",
251...| "bytespersec": 0,
252...| "iops": 0
253...| }
254...| },
255...| "Fstype": "xfs",
256...| "Workdir": "",
257...| "Entrypoint": null,
258...| "Cmd": [
259...| "sh"
260...| ],
261...| "Envs": {
262...| "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
263...| },
264...| "Initialize": true
265...|}
266I0922 14:37:53.406640 6395 devicemap.go:196] insert volume /dev/mapper/docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d source /dev/mapper/docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d fstype xfs
267I0922 14:37:53.406648 6395 devicemap.go:280] insert volume etchosts-volume to /etc/hosts on 0
268I0922 14:37:53.406804 6395 vm_states.go:67] initial vm spec: {
269 "hostname": "busybox-8924984816",
270 "containers": [
271 {
272 "id": "4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d",
273 "rootfs": "/rootfs",
274 "fstype": "xfs",
275 "image": "",
276 "fsmap": [
277 {
278 "source": "vzlFZkbYaZ",
279 "path": "/etc/hosts",
280 "readOnly": false,
281 "dockerVolume": false
282 }
283 ],
284 "process": {
285 "terminal": true,
286 "stdio": 1,
287 "args": [
288 "sh"
289 ],
290 "envs": [
291 {
292 "env": "PATH",
293 "value": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
294 }
295 ],
296 "workdir": "/"
297 },
298 "restartPolicy": "never",
299 "initialize": true
300 }
301 ],
302 "shareDir": "share_dir"
303 }
304I0922 14:37:53.406817 6395 context.go:224] found container 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d at 0
305I0922 14:37:53.406823 6395 vm_states.go:75] attach pending client for 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d
306I0922 14:37:53.406828 6395 vm_states.go:247] Connecting tty for 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d on session 1
307I0922 14:37:53.406832 6395 context.go:224] found container 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d at 0
308I0922 14:37:53.406835 6395 vm_states.go:75] attach pending client for 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d
309I0922 14:37:53.406837 6395 vm_states.go:247] Connecting tty for 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d on session 1
310I0922 14:37:53.406862 6395 context.go:260] VM vm-OmUeiQBIAF: state change from INIT to 'STARTING'
311I0922 14:37:53.406870 6395 qmp_handler.go:296] got new session
312I0922 14:37:53.406881 6395 qmp_handler.go:225] Begin process command session
313I0922 14:37:53.406890 6395 qmp_handler.go:243] sending command (1) {"execute":"human-monitor-command","arguments":{"command-line":"drive_add dummy file=/dev/mapper/docker-253:0-1573769-c6579d288d986f1982207f3235a9bb7b7ca2f73b1a05412d2c84b5a626358c5d,if=none,id=drive0,format=raw,cache=writeback"}}
314I0922 14:37:53.412166 6395 qmp_handler.go:103] got a message {"return": "OK\r\n"}
315I0922 14:37:53.412223 6395 qmp_handler.go:243] sending command (1) {"execute":"device_add","arguments":{"bus":"scsi0.0","drive":"drive0","driver":"scsi-hd","id":"scsi-disk0","scsi-id":"0"}}
316I0922 14:37:53.414208 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 12(EVENT_INTERFACE_ADD)
317I0922 14:37:53.414239 6395 qmp_wrapper_amd64.go:17] send net to qemu at 25
318I0922 14:37:53.414266 6395 qmp_handler.go:296] got new session
319I0922 14:37:53.424256 6395 qmp_handler.go:103] got a message {"return": {}}
320I0922 14:37:53.424291 6395 qmp_handler.go:302] session finished, buffer size 2
321I0922 14:37:53.424297 6395 qmp_handler.go:305] success
322I0922 14:37:53.424316 6395 qmp_handler.go:225] Begin process command session
323I0922 14:37:53.424332 6395 qmp_handler.go:238] send cmd with scm (24 bytes) (1) {"execute":"getfd","arguments":{"fdname":"fdeth0"}}
324I0922 14:37:53.424587 6395 qmp_handler.go:103] got a message {"return": {}}
325I0922 14:37:53.424759 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 9(EVENT_BLOCK_INSERTED)
326I0922 14:37:53.425245 6395 qmp_handler.go:243] sending command (1) {"execute":"netdev_add","arguments":{"fd":"fdeth0","id":"eth0","type":"tap"}}
327I0922 14:37:53.425864 6395 qmp_handler.go:103] got a message {"return": {}}
328I0922 14:37:53.426181 6395 qmp_handler.go:243] sending command (1) {"execute":"device_add","arguments":{"addr":"0x5","bus":"pci.0","driver":"virtio-net-pci","id":"eth0","mac":"52:54:58:d3:46:96","netdev":"eth0"}}
329I0922 14:37:53.433352 6395 qmp_handler.go:103] got a message {"return": {}}
330I0922 14:37:53.433726 6395 qmp_handler.go:302] session finished, buffer size 1
331I0922 14:37:53.434010 6395 qmp_handler.go:305] success
332I0922 14:37:53.434210 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 14(EVENT_INTERFACE_INSERTED)
333I0922 14:37:53.434406 6395 vm_states.go:470] device ready, could run pod.
334I0922 14:37:54.392336 6395 init_comm.go:68] [console] Initializing cgroup subsys cpuset
335I0922 14:37:54.392860 6395 init_comm.go:68] [console] Initializing cgroup subsys cpu
336I0922 14:37:54.393325 6395 init_comm.go:68] [console] Initializing cgroup subsys cpuacct
337I0922 14:37:54.393679 6395 init_comm.go:68] [console] Linux version 4.4.12-hyper (dev@hyper.sh) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-4) (GCC) ) #1 SMP Tue Jun 7 19:29:06 UTC 2016
338I0922 14:37:54.394438 6395 init_comm.go:68] [console] Command line: console=ttyS0 panic=1 no_timer_check
339I0922 14:37:54.394898 6395 init_comm.go:68] [console] x86/fpu: Legacy x87 FPU detected.
340I0922 14:37:54.395164 6395 init_comm.go:68] [console] x86/fpu: Using 'lazy' FPU context switches.
341I0922 14:37:54.395532 6395 init_comm.go:68] [console] e820: BIOS-provided physical RAM map:
342I0922 14:37:54.395850 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
343I0922 14:37:54.396452 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
344I0922 14:37:54.397057 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
345I0922 14:37:54.397683 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffbfff] usable
346I0922 14:37:54.397920 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000007ffc000-0x0000000007ffffff] reserved
347I0922 14:37:54.398608 6395 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
348I0922 14:37:54.398833 6395 init_comm.go:68] [console] NX (Execute Disable) protection: active
349I0922 14:37:54.399181 6395 init_comm.go:68] [console] SMBIOS 2.4 present.
350I0922 14:37:54.399523 6395 init_comm.go:68] [console] e820: last_pfn = 0x7ffc max_arch_pfn = 0x400000000
351I0922 14:37:54.400106 6395 init_comm.go:68] [console] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT
352I0922 14:37:54.400280 6395 init_comm.go:68] [console] found SMP MP-table at [mem 0x000f6b80-0x000f6b8f] mapped at [ffff8800000f6b80]
353I0922 14:37:54.400750 6395 init_comm.go:68] [console] RAMDISK: [mem 0x07af5000-0x07feffff]
354I0922 14:37:54.401205 6395 init_comm.go:68] [console] ACPI: Early table checksum verification disabled
355I0922 14:37:54.401308 6395 init_comm.go:68] [console] ACPI: RSDP 0x00000000000F6A00 000014 (v00 BOCHS )
356I0922 14:37:54.402115 6395 init_comm.go:68] [console] ACPI: RSDT 0x0000000007FFF6D8 00002C (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
357I0922 14:37:54.402373 6395 init_comm.go:68] [console] ACPI: FACP 0x0000000007FFF5EC 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
358I0922 14:37:54.403148 6395 init_comm.go:68] [console] ACPI: DSDT 0x0000000007FFE040 0015AC (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
359I0922 14:37:54.403502 6395 init_comm.go:68] [console] ACPI: FACS 0x0000000007FFE000 000040
360I0922 14:37:54.403729 6395 init_comm.go:68] [console] ACPI: APIC 0x0000000007FFF660 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
361I0922 14:37:54.404118 6395 init_comm.go:68] [console] No NUMA configuration found
362I0922 14:37:54.404663 6395 init_comm.go:68] [console] Faking a node at [mem 0x0000000000000000-0x0000000007ffbfff]
363I0922 14:37:54.405158 6395 init_comm.go:68] [console] NODE_DATA(0) allocated [mem 0x07ae3000-0x07af4fff]
364I0922 14:37:54.405360 6395 init_comm.go:68] [console] Zone ranges:
365I0922 14:37:54.405857 6395 init_comm.go:68] [console] DMA [mem 0x0000000000001000-0x0000000000ffffff]
366I0922 14:37:54.406382 6395 init_comm.go:68] [console] DMA32 [mem 0x0000000001000000-0x0000000007ffbfff]
367I0922 14:37:54.406593 6395 init_comm.go:68] [console] Normal empty
368I0922 14:37:54.406916 6395 init_comm.go:68] [console] Movable zone start for each node
369I0922 14:37:54.407091 6395 init_comm.go:68] [console] Early memory node ranges
370I0922 14:37:54.407571 6395 init_comm.go:68] [console] node 0: [mem 0x0000000000001000-0x000000000009efff]
371I0922 14:37:54.408087 6395 init_comm.go:68] [console] node 0: [mem 0x0000000000100000-0x0000000007ffbfff]
372I0922 14:37:54.408684 6395 init_comm.go:68] [console] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffbfff]
373I0922 14:37:54.408870 6395 init_comm.go:68] [console] ACPI: PM-Timer IO Port: 0x608
374I0922 14:37:54.409097 6395 init_comm.go:68] [console] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
375I0922 14:37:54.409342 6395 init_comm.go:68] [console] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
376I0922 14:37:54.409581 6395 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
377I0922 14:37:54.409819 6395 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
378I0922 14:37:54.410393 6395 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
379I0922 14:37:54.410553 6395 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
380I0922 14:37:54.410790 6395 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
381I0922 14:37:54.411318 6395 init_comm.go:68] [console] Using ACPI (MADT) for SMP configuration information
382I0922 14:37:54.411726 6395 init_comm.go:68] [console] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
383I0922 14:37:54.412266 6395 init_comm.go:68] [console] e820: [mem 0x08000000-0xfffbffff] available for PCI devices
384I0922 14:37:54.412406 6395 init_comm.go:68] [console] Booting paravirtualized kernel on bare hardware
385I0922 14:37:54.412683 6395 init_comm.go:68] [console] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
386I0922 14:37:54.413272 6395 init_comm.go:68] [console] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_ids:1
387I0922 14:37:54.413885 6395 init_comm.go:68] [console] PERCPU: Embedded 31 pages/cpu @ffff880007800000 s89624 r8192 d29160 u2097152
388I0922 14:37:54.414546 6395 init_comm.go:68] [console] Built 1 zonelists in Node order, mobility grouping on. Total pages: 32133
389I0922 14:37:54.414718 6395 init_comm.go:68] [console] Policy zone: DMA32
390I0922 14:37:54.415352 6395 init_comm.go:68] [console] Kernel command line: console=ttyS0 panic=1 no_timer_check
391I0922 14:37:54.416176 6395 init_comm.go:68] [console] PID hash table entries: 512 (order: 0, 4096 bytes)
392I0922 14:37:54.416421 6395 init_comm.go:68] [console] Memory: 114628K/130664K available (4658K kernel code, 576K rwdata, 1472K rodata, 876K init, 756K bss, 16036K reserved, 0K cma-reserved)
393I0922 14:37:54.416723 6395 init_comm.go:68] [console] Hierarchical RCU implementation.
394I0922 14:37:54.417098 6395 init_comm.go:68] [console] Build-time adjustment of leaf fanout to 64.
395I0922 14:37:54.417498 6395 init_comm.go:68] [console] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=1.
396I0922 14:37:54.418017 6395 init_comm.go:68] [console] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
397I0922 14:37:54.418175 6395 init_comm.go:68] [console] NR_IRQS:4352 nr_irqs:256 16
398I0922 14:37:54.418438 6395 init_comm.go:68] [console] Console: colour *CGA 80x25
399I0922 14:37:54.418768 6395 init_comm.go:68] [console] console [ttyS0] enabled
400I0922 14:37:54.440103 6395 init_comm.go:68] [console] tsc: Fast TSC calibration using PIT
401I0922 14:37:54.440743 6395 init_comm.go:68] [console] tsc: Detected 2494.551 MHz processor
402I0922 14:37:54.442931 6395 init_comm.go:68] [console] Calibrating delay loop (skipped), value calculated using timer frequency.. 4989.10 BogoMIPS (lpj=2494551)
403I0922 14:37:54.443506 6395 init_comm.go:68] [console] pid_max: default: 32768 minimum: 301
404I0922 14:37:54.444289 6395 init_comm.go:68] [console] ACPI: Core revision 20150930
405I0922 14:37:54.468838 6395 init_comm.go:68] [console] ACPI: 1 ACPI AML tables successfully acquired and loaded
406I0922 14:37:54.471151 6395 init_comm.go:68] [console] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
407I0922 14:37:54.473056 6395 init_comm.go:68] [console] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
408I0922 14:37:54.473958 6395 init_comm.go:68] [console] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
409I0922 14:37:54.474307 6395 init_comm.go:68] [console] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
410I0922 14:37:54.482362 6395 init_comm.go:68] [console] Initializing cgroup subsys io
411I0922 14:37:54.482986 6395 init_comm.go:68] [console] Initializing cgroup subsys memory
412I0922 14:37:54.483858 6395 init_comm.go:68] [console] Initializing cgroup subsys devices
413I0922 14:37:54.484510 6395 init_comm.go:68] [console] Initializing cgroup subsys freezer
414I0922 14:37:54.485054 6395 init_comm.go:68] [console] Initializing cgroup subsys net_cls
415I0922 14:37:54.485419 6395 init_comm.go:68] [console] Initializing cgroup subsys perf_event
416I0922 14:37:54.485915 6395 init_comm.go:68] [console] Initializing cgroup subsys net_prio
417I0922 14:37:54.486512 6395 init_comm.go:68] [console] Initializing cgroup subsys pids
418I0922 14:37:54.487142 6395 init_comm.go:68] [console] Initializing cgroup subsys debug
419I0922 14:37:54.489340 6395 init_comm.go:68] [console] process: using mwait in idle threads
420I0922 14:37:54.490152 6395 init_comm.go:68] [console] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
421I0922 14:37:54.490828 6395 init_comm.go:68] [console] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
422I0922 14:37:54.646675 6395 init_comm.go:68] [console] Freeing SMP alternatives memory: 20K (ffffffff8176b000 - ffffffff81770000)
423I0922 14:37:54.664747 6395 init_comm.go:68] [console] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
424I0922 14:37:54.768225 6395 init_comm.go:68] [console] smpboot: CPU0: Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz (family: 0x6, model: 0xf, stepping: 0xb)
425I0922 14:37:54.769762 6395 init_comm.go:68] [console] Performance Events: unsupported p6 CPU model 15 no PMU driver, software events only.
426I0922 14:37:54.776189 6395 init_comm.go:68] [console] x86: Booted up 1 node, 1 CPUs
427I0922 14:37:54.777146 6395 init_comm.go:68] [console] smpboot: Total of 1 processors activated (4989.10 BogoMIPS)
428I0922 14:37:54.785923 6395 init_comm.go:68] [console] devtmpfs: initialized
429I0922 14:37:54.803456 6395 init_comm.go:68] [console] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
430I0922 14:37:54.809746 6395 init_comm.go:68] [console] NET: Registered protocol family 16
431I0922 14:37:54.812597 6395 init_comm.go:68] [console] cpuidle: using governor ladder
432I0922 14:37:54.813263 6395 init_comm.go:68] [console] cpuidle: using governor menu
433I0922 14:37:54.814230 6395 init_comm.go:68] [console] ACPI: bus type PCI registered
434I0922 14:37:54.814909 6395 init_comm.go:68] [console] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
435I0922 14:37:54.816199 6395 init_comm.go:68] [console] PCI: Using configuration type 1 for base access
436I0922 14:37:54.829846 6395 init_comm.go:68] [console] ACPI: Added _OSI(Module Device)
437I0922 14:37:54.830300 6395 init_comm.go:68] [console] ACPI: Added _OSI(Processor Device)
438I0922 14:37:54.830747 6395 init_comm.go:68] [console] ACPI: Added _OSI(3.0 _SCP Extensions)
439I0922 14:37:54.831382 6395 init_comm.go:68] [console] ACPI: Added _OSI(Processor Aggregator Device)
440I0922 14:37:54.849780 6395 init_comm.go:68] [console] ACPI: Interpreter enabled
441I0922 14:37:54.850656 6395 init_comm.go:68] [console] ACPI: (supports S0 S5)
442I0922 14:37:54.851307 6395 init_comm.go:68] [console] ACPI: Using IOAPIC for interrupt routing
443I0922 14:37:54.852650 6395 init_comm.go:68] [console] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
444I0922 14:37:54.887717 6395 init_comm.go:68] [console] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
445I0922 14:37:54.888925 6395 init_comm.go:68] [console] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
446I0922 14:37:54.889736 6395 init_comm.go:68] [console] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
447I0922 14:37:54.893378 6395 init_comm.go:68] [console] acpiphp: Slot [2] registered
448I0922 14:37:54.894001 6395 init_comm.go:68] [console] acpiphp: Slot [3] registered
449I0922 14:37:54.894764 6395 init_comm.go:68] [console] acpiphp: Slot [4] registered
450I0922 14:37:54.895465 6395 init_comm.go:68] [console] acpiphp: Slot [5] registered
451I0922 14:37:54.896021 6395 init_comm.go:68] [console] acpiphp: Slot [6] registered
452I0922 14:37:54.896788 6395 init_comm.go:68] [console] acpiphp: Slot [7] registered
453I0922 14:37:54.897539 6395 init_comm.go:68] [console] acpiphp: Slot [8] registered
454I0922 14:37:54.898222 6395 init_comm.go:68] [console] acpiphp: Slot [9] registered
455I0922 14:37:54.898829 6395 init_comm.go:68] [console] acpiphp: Slot [10] registered
456I0922 14:37:54.899749 6395 init_comm.go:68] [console] acpiphp: Slot [11] registered
457I0922 14:37:54.900531 6395 init_comm.go:68] [console] acpiphp: Slot [12] registered
458I0922 14:37:54.901269 6395 init_comm.go:68] [console] acpiphp: Slot [13] registered
459I0922 14:37:54.901896 6395 init_comm.go:68] [console] acpiphp: Slot [14] registered
460I0922 14:37:54.902771 6395 init_comm.go:68] [console] acpiphp: Slot [15] registered
461I0922 14:37:54.903607 6395 init_comm.go:68] [console] acpiphp: Slot [16] registered
462I0922 14:37:54.904449 6395 init_comm.go:68] [console] acpiphp: Slot [17] registered
463I0922 14:37:54.905084 6395 init_comm.go:68] [console] acpiphp: Slot [18] registered
464I0922 14:37:54.905702 6395 init_comm.go:68] [console] acpiphp: Slot [19] registered
465I0922 14:37:54.906360 6395 init_comm.go:68] [console] acpiphp: Slot [20] registered
466I0922 14:37:54.906929 6395 init_comm.go:68] [console] acpiphp: Slot [21] registered
467I0922 14:37:54.907535 6395 init_comm.go:68] [console] acpiphp: Slot [22] registered
468I0922 14:37:54.908026 6395 init_comm.go:68] [console] acpiphp: Slot [23] registered
469I0922 14:37:54.908602 6395 init_comm.go:68] [console] acpiphp: Slot [24] registered
470I0922 14:37:54.909137 6395 init_comm.go:68] [console] acpiphp: Slot [25] registered
471I0922 14:37:54.909533 6395 init_comm.go:68] [console] acpiphp: Slot [26] registered
472I0922 14:37:54.909877 6395 init_comm.go:68] [console] acpiphp: Slot [27] registered
473I0922 14:37:54.910261 6395 init_comm.go:68] [console] acpiphp: Slot [28] registered
474I0922 14:37:54.910592 6395 init_comm.go:68] [console] acpiphp: Slot [29] registered
475I0922 14:37:54.910921 6395 init_comm.go:68] [console] acpiphp: Slot [30] registered
476I0922 14:37:54.911334 6395 init_comm.go:68] [console] acpiphp: Slot [31] registered
477I0922 14:37:54.911773 6395 init_comm.go:68] [console] PCI host bridge to bus 0000:00
478I0922 14:37:54.912305 6395 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
479I0922 14:37:54.912601 6395 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
480I0922 14:37:54.912855 6395 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
481I0922 14:37:54.913238 6395 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x08000000-0xfebfffff window]
482I0922 14:37:54.913576 6395 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [bus 00-ff]
483I0922 14:37:54.922777 6395 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
484I0922 14:37:54.923142 6395 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
485I0922 14:37:54.923454 6395 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
486I0922 14:37:54.923657 6395 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
487I0922 14:37:54.925271 6395 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
488I0922 14:37:54.925556 6395 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
489I0922 14:37:54.970952 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
490I0922 14:37:54.973151 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
491I0922 14:37:54.974232 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
492I0922 14:37:54.975358 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
493I0922 14:37:54.976183 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
494I0922 14:37:54.979161 6395 init_comm.go:68] [console] ACPI: Enabled 16 GPEs in block 00 to 0F
495I0922 14:37:54.983150 6395 init_comm.go:68] [console] vgaarb: loaded
496I0922 14:37:54.984339 6395 init_comm.go:68] [console] SCSI subsystem initialized
497I0922 14:37:54.985532 6395 init_comm.go:68] [console] PCI: Using ACPI for IRQ routing
498I0922 14:37:54.992506 6395 init_comm.go:68] [console] clocksource: Switched to clocksource refined-jiffies
499I0922 14:37:54.995190 6395 init_comm.go:68] [console] pnp: PnP ACPI init
500I0922 14:37:55.001066 6395 init_comm.go:68] [console] pnp: PnP ACPI: found 5 devices
501I0922 14:37:55.028071 6395 init_comm.go:68] [console] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
502I0922 14:37:55.028591 6395 init_comm.go:68] [console] clocksource: Switched to clocksource acpi_pm
503I0922 14:37:55.031089 6395 init_comm.go:68] [console] NET: Registered protocol family 2
504I0922 14:37:55.036198 6395 init_comm.go:68] [console] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
505I0922 14:37:55.036740 6395 init_comm.go:68] [console] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
506I0922 14:37:55.037118 6395 init_comm.go:68] [console] TCP: Hash tables configured (established 1024 bind 1024)
507I0922 14:37:55.037979 6395 init_comm.go:68] [console] UDP hash table entries: 256 (order: 1, 8192 bytes)
508I0922 14:37:55.038303 6395 init_comm.go:68] [console] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
509I0922 14:37:55.039772 6395 init_comm.go:68] [console] NET: Registered protocol family 1
510I0922 14:37:55.040264 6395 init_comm.go:68] [console] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
511I0922 14:37:55.040612 6395 init_comm.go:68] [console] pci 0000:00:01.0: PIIX3: Enabling Passive Release
512I0922 14:37:55.040959 6395 init_comm.go:68] [console] pci 0000:00:01.0: Activating ISA DMA hang workarounds
513I0922 14:37:55.044941 6395 init_comm.go:68] [console] Trying to unpack rootfs image as initramfs...
514I0922 14:37:55.448006 6395 init_comm.go:68] [console] Freeing initrd memory: 5100K (ffff880007af5000 - ffff880007ff0000)
515I0922 14:37:55.452187 6395 init_comm.go:68] [console] futex hash table entries: 256 (order: 2, 16384 bytes)
516I0922 14:37:55.457490 6395 init_comm.go:68] [console] SGI XFS with ACLs, security attributes, no debug enabled
517I0922 14:37:55.459532 6395 init_comm.go:68] [console] 9p: Installing v9fs 9p2000 file system support
518I0922 14:37:55.492332 6395 init_comm.go:68] [console] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
519I0922 14:37:55.493316 6395 init_comm.go:68] [console] io scheduler noop registered
520I0922 14:37:55.493984 6395 init_comm.go:68] [console] io scheduler cfq registered (default)
521I0922 14:37:55.495182 6395 init_comm.go:68] [console] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
522I0922 14:37:55.495417 6395 init_comm.go:68] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
523I0922 14:37:55.497143 6395 init_comm.go:68] [console] Warning: Processor Platform Limit event detected, but not handled.
524I0922 14:37:55.497337 6395 init_comm.go:68] [console] Consider compiling CPUfreq support into your kernel.
525I0922 14:37:55.800991 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
526I0922 14:37:55.802078 6395 init_comm.go:68] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
527I0922 14:37:56.089112 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
528I0922 14:37:56.089938 6395 init_comm.go:68] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
529I0922 14:37:56.373868 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
530I0922 14:37:56.374718 6395 init_comm.go:68] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
531I0922 14:37:56.659368 6395 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
532I0922 14:37:56.660153 6395 init_comm.go:68] [console] virtio-pci 0000:00:05.0: virtio_pci: leaving for legacy driver
533I0922 14:37:56.663381 6395 init_comm.go:68] [console] tsc: Refined TSC clocksource calibration: 2494.530 MHz
534I0922 14:37:56.664560 6395 init_comm.go:68] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x23f50a6d19f, max_idle_ns: 440795231317 ns
535I0922 14:37:56.666104 6395 init_comm.go:68] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
536I0922 14:37:56.689916 6395 init_comm.go:68] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
537I0922 14:37:56.736483 6395 init_comm.go:68] [console] brd: module loaded
538I0922 14:37:56.737682 6395 init_comm.go:68] [console] loop: module loaded
539I0922 14:37:56.741012 6395 init_comm.go:68] [console] scsi host0: Virtio SCSI HBA
540I0922 14:37:56.753166 6395 init_comm.go:68] [console] scsi 0:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.0. PQ: 0 ANSI: 5
541I0922 14:37:56.917726 6395 init_comm.go:68] [console] sd 0:0:0:0: [sda] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
542I0922 14:37:56.919634 6395 init_comm.go:68] [console] sd 0:0:0:0: [sda] Write Protect is off
543I0922 14:37:56.921183 6395 init_comm.go:68] [console] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
544I0922 14:37:56.923603 6395 init_comm.go:68] [console] sd 0:0:0:0: Attached scsi generic sg0 type 0
545I0922 14:37:56.929413 6395 init_comm.go:68] [console] rtc_cmos 00:00: RTC can wake from S4
546I0922 14:37:56.938322 6395 init_comm.go:68] [console] sd 0:0:0:0: [sda] Attached SCSI disk
547I0922 14:37:56.940284 6395 init_comm.go:68] [console] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
548I0922 14:37:56.941850 6395 init_comm.go:68] [console] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram
549I0922 14:37:56.943635 6395 init_comm.go:68] [console] Initializing XFRM netlink socket
550I0922 14:37:56.944714 6395 init_comm.go:68] [console] NET: Registered protocol family 10
551I0922 14:37:56.952504 6395 init_comm.go:68] [console] NET: Registered protocol family 17
552I0922 14:37:56.954248 6395 init_comm.go:68] [console] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
553I0922 14:37:56.955081 6395 init_comm.go:68] [console] Bridge firewalling registered
554I0922 14:37:56.956252 6395 init_comm.go:68] [console] 9pnet: Installing 9P2000 support
555I0922 14:37:56.959548 6395 init_comm.go:68] [console] registered taskstats version 1
556I0922 14:37:56.963016 6395 init_comm.go:68] [console] rtc_cmos 00:00: setting system clock to 2016-09-22 06:37:56 UTC (1474526276)
557I0922 14:37:56.988656 6395 init_comm.go:68] [console] Freeing unused kernel memory: 876K (ffffffff81690000 - ffffffff8176b000)
558I0922 14:37:57.072418 6395 init_comm.go:68] [console] create directory /sys
559I0922 14:37:57.075241 6395 init_comm.go:68] [console] create directory /sbin
560I0922 14:37:57.076096 6395 init_comm.go:68] [console] create directory /proc
561I0922 14:37:57.083983 6395 init_comm.go:68] [console] uptime 2.53 0.21
562I0922 14:37:57.084175 6395 init_comm.go:68] [console]
563I0922 14:37:57.091083 6395 init_comm.go:68] [console] create directory /dev/pts
564I0922 14:37:57.101007 6395 init_comm.go:68] [console] vboxguest: disagrees about version of symbol module_layout
565I0922 14:37:57.104065 6395 init_comm.go:68] [console] insmod: init_module: /vboxguest.ko: Invalid module format
566I0922 14:37:57.106845 6395 init_comm.go:68] [console] fail to load modules
567I0922 14:37:57.118715 6395 init_comm.go:68] [console] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000ff00
568I0922 14:37:57.118777 6395 init_comm.go:68] [console]
569I0922 14:37:57.119490 6395 init_comm.go:68] [console] CPU: 0 PID: 1 Comm: init Not tainted 4.4.12-hyper #1
570I0922 14:37:57.120215 6395 init_comm.go:68] [console] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
571I0922 14:37:57.121111 6395 init_comm.go:68] [console] 0000000000000000 ffffffff8125831c ffffffff81572af0 ffff88000749feb8
572I0922 14:37:57.121858 6395 init_comm.go:68] [console] ffffffff810c5bca 0000000000000010 ffff88000749fec8 ffff88000749fe68
573I0922 14:37:57.122592 6395 init_comm.go:68] [console] ffffffff810c338f 000000000000ff00 ffff880007492c10 0000000000000000
574I0922 14:37:57.122815 6395 init_comm.go:68] [console] Call Trace:
575I0922 14:37:57.123501 6395 init_comm.go:68] [console] [<ffffffff8125831c>] ? dump_stack+0x5c/0x80
576I0922 14:37:57.123917 6395 init_comm.go:68] [console] [<ffffffff810c5bca>] ? panic+0xc3/0x1e0
577I0922 14:37:57.124438 6395 init_comm.go:68] [console] [<ffffffff810c338f>] ? perf_event_exit_task+0x9f/0x350
578I0922 14:37:57.124880 6395 init_comm.go:68] [console] [<ffffffff8104e408>] ? do_exit+0xa68/0xa70
579I0922 14:37:57.125368 6395 init_comm.go:68] [console] [<ffffffff8104e474>] ? do_group_exit+0x34/0xa0
580I0922 14:37:57.126247 6395 init_comm.go:68] [console] [<ffffffff8104e4eb>] ? SyS_exit_group+0xb/0x10
581I0922 14:37:57.126795 6395 init_comm.go:68] [console] [<ffffffff8148a3ee>] ? entry_SYSCALL_64_fastpath+0x12/0x71
582I0922 14:37:57.127344 6395 init_comm.go:68] [console] Kernel Offset: disabled
583I0922 14:37:58.129525 6395 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1474526278, "microseconds": 129358}, "event": "SHUTDOWN"}
584I0922 14:37:58.129590 6395 qmp_handler.go:107] got event: SHUTDOWN
585I0922 14:37:58.129607 6395 qmp_handler.go:152] Shutdown, quit QMP receiver
586I0922 14:37:58.129618 6395 qmp_handler.go:323] got QMP event SHUTDOWN
587I0922 14:37:58.129623 6395 qmp_handler.go:325] got QMP shutdown event, quit...
588I0922 14:37:58.129632 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 1(EVENT_VM_EXIT)
589I0922 14:37:58.129641 6395 vm_states.go:311] Got VM shutdown event, go to cleaning up
590I0922 14:37:58.129647 6395 vm_states.go:36] VM has exit...
591I0922 14:37:58.129662 6395 devicemap.go:488] remove network card 0: 192.168.123.2
592I0922 14:37:58.129670 6395 context.go:260] VM vm-OmUeiQBIAF: state change from STARTING to 'DESTROYING'
593I0922 14:37:58.129709 6395 hypervisor.go:29] vm vm-OmUeiQBIAF: main event loop got message 13(EVENT_INTERFACE_DELETE)
594I0922 14:37:58.129715 6395 devicemap.go:442] interface 0 released
595I0922 14:37:58.129720 6395 vm_states.go:359] Unplug interface return with true
596I0922 14:37:58.129917 6395 context.go:247] no more device to release/remove/umount, quit
597I0922 14:37:58.129942 6395 qemu_process.go:86] quit watch dog.
598I0922 14:37:58.130156 6395 vm.go:275] Get the response from VM, VM id is vm-OmUeiQBIAF!
599I0922 14:37:58.130184 6395 pod.go:332] unlock pod pod-htusddiFbu for operation start
600I0922 14:37:58.130190 6395 pod.go:335] successfully unlock pod pod-htusddiFbu for operation start
601E0922 14:37:58.130195 6395 run.go:86] VM vm-OmUeiQBIAF start failed with code 2: VM shut down
602E0922 14:37:58.130818 6395 server.go:170] Handler for POST /v1.17/pod/start returned error: VM vm-OmUeiQBIAF start failed with code 2: VM shut down
6032016/09/22 14:37:58 http: response.WriteHeader on hijacked connection
6042016/09/22 14:37:58 http: response.Write on hijacked connection
605I0922 14:37:58.132707 6395 server.go:152] Calling GET /v0.6.2/list
606I0922 14:37:58.132734 6395 pod_routes.go:52] List type is container, specified pod: [pod-htusddiFbu], specified vm: [], list auxiliary pod: false
607I0922 14:37:58.133490 6395 server.go:152] Calling GET /v0.6.2/exitcode
608I0922 14:37:58.133540 6395 exec.go:14] Get container id 4c09260a53165e138597808034d9ab29b11e0ef67e9bd57e964d74a3ea8be10d, exec id
609I0922 14:37:58.154238 6395 tty.go:440] Input byte chan closed, close the output string chan
610I0922 14:37:58.154278 6395 init_comm.go:70] console output end
611E0922 14:37:58.154417 6395 tty.go:92] read tty data failed
612I0922 14:37:58.154428 6395 tty.go:153] tty socket closed, quit the reading goroutine EOF
613I0922 14:37:58.154448 6395 tty.go:120] tty chan closed, quit sent goroutine
614E0922 14:37:58.154461 6395 init_comm.go:99] read init data failed
615E0922 14:37:58.154465 6395 init_comm.go:146] read init message failed... EOF
616I0922 14:37:58.175325 6395 pod.go:852] cleanupEtcHost for pod-htusddiFbu
617I0922 14:37:58.175341 6395 etchosts.go:84] cleanupHosts /var/lib/hyper/hosts/pod-htusddiFbu, /var/lib/hyper/hosts/pod-htusddiFbu/hosts