· 10 years ago · Sep 22, 2016, 09:10 AM
1[root@localhost ~]# hyperctl run -t busybox
2/ # ls /dev/kvm
3ls: /dev/kvm: No such file or directory
4/ # df -h
5Filesystem Size Used Available Use% Mounted on
6/dev/sda 10.0G 34.1M 10.0G 0% /
7devtmpfs 56.0M 0 56.0M 0% /dev
8tmpfs 58.9M 0 58.9M 0% /dev/shm
9share_dir 1.0M 4.0K 1020.0K 0% /etc/hosts
10/ # exit
11[root@localhost ~]# hyperctl list
12POD ID POD Name VM name Status
13pod-evSgAursPF busybox-6199998260 pending
14pod-orbBigFyPD ubuntu-7378494712 pending
15pod-vQpEHWbgiu busybox-8936144739 pending
16pod-OUfBbohkAW busybox-7866800518 succeeded
17
18
19### Simple chagnes ####
20[ray@localhost hyperd]$ git diff
21diff --git a/Godeps/_workspace/src/github.com/hyperhq/runv/hypervisor/qemu/qemu_amd64.go b/Godeps/_workspace/src/github.com/hyperhq/runv/hypervisor/qemu/qemu_amd64.go
22index b8cd4df..58f3263 100644
23--- a/Godeps/_workspace/src/github.com/hyperhq/runv/hypervisor/qemu/qemu_amd64.go
24+++ b/Godeps/_workspace/src/github.com/hyperhq/runv/hypervisor/qemu/qemu_amd64.go
25@@ -39,7 +39,7 @@ func (qc *QemuContext) arguments(ctx *hypervisor.VmContext) []string {
26 }
27
28 params := []string{
29- "-machine", machineClass + ",accel=kvm,usb=off", "-global", "kvm-pit.lost_tick_policy=discard", "-cpu", "host"}
30+ "-machine", machineClass + ",accel=kvm,usb=off", "-global", "kvm-pit.lost_tick_policy=discard", "-cpu", "core2duo"}
31 if _, err := os.Stat("/dev/kvm"); os.IsNotExist(err) {
32 glog.V(1).Info("kvm not exist change to no kvm mode")
33 params = []string{"-machine", machineClass + ",usb=off", "-cpu", "core2duo"}
34
35
36
37
38##### hyperd log ####
39[root@localhost ~]# hyperd -v 3
40I0922 17:02:22.039102 5517 hyperd.go:106] The config file is
41I0922 17:02:22.040279 5517 daemon.go:141] The config: kernel=/var/lib/hyper/kernel, initrd=/var/lib/hyper/hyper-initrd.img
42I0922 17:02:22.040508 5517 daemon.go:143] The config: vbox image=
43I0922 17:02:22.040717 5517 daemon.go:146] The config: bridge=, ip=
44I0922 17:02:22.040882 5517 daemon.go:149] The config: bios=, cbfs=
45DEBU[0000] Using default logging driver none
46DEBU[0000] devicemapper: driver version is 4.34.0
47DEBU[0000] devmapper: Generated prefix: docker-253:0-1573769
48DEBU[0000] devmapper: Checking for existence of the pool docker-253:0-1573769-pool
49DEBU[0000] devmapper: poolDataMajMin=7:0 poolMetaMajMin=7:1
50
51DEBU[0000] devmapper: Major:Minor for device: /dev/loop0 is:7:0
52DEBU[0000] devmapper: Major:Minor for device: /dev/loop1 is:7:1
53DEBU[0000] devmapper: loadDeviceFilesOnStart()
54DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/44d34d6d55ddefd7ef34830a749cc41810d486c026744ca27a90030986ad4cc4
55DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/44d34d6d55ddefd7ef34830a749cc41810d486c026744ca27a90030986ad4cc4-init
56DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15
57DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/831deeebf58f19fa49f3be37dc6ded131b5dfb8e552869ffc53694e9984b0131
58DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/a980b8a088852a01f42768b3906ada30b1ecad14c8ce765a4c9cb524a4eef2c8
59DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/b6b249718725ec9b3676a6003d4c29c37a0621d56dfb072790d0569c7fa4c08e
60DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/b6b249718725ec9b3676a6003d4c29c37a0621d56dfb072790d0569c7fa4c08e-init
61DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/ba9e03dd15779eba57bf82a0cca79abcb4674c55dbb51bb1cfbb4499be316874
62DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/ba9e03dd15779eba57bf82a0cca79abcb4674c55dbb51bb1cfbb4499be316874-init
63DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/base
64DEBU[0000] devmapper: Skipping file /var/lib/hyper/devicemapper/metadata/deviceset-metadata
65DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/e11ca2da1939fcc8b5148ed32315a0d63ad9aa28afb4bd6dda56fa4a045f0bd8
66DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/e139596f77e84ef2b9ac71cee2b5d29bb2e2a25b8de8032a8049893f68730f68
67DEBU[0000] devmapper: Loading data for file /var/lib/hyper/devicemapper/metadata/f3ea03622be802c772076a261c5d0230a6de98945b1c96e786fa2d6fb0accef4
68DEBU[0000] devmapper: Skipping file /var/lib/hyper/devicemapper/metadata/transaction-metadata
69DEBU[0000] devmapper: loadDeviceFilesOnStart() END
70DEBU[0000] devmapper: constructDeviceIDMap()
71DEBU[0000] devmapper: Added deviceId=4 to DeviceIdMap
72DEBU[0000] devmapper: Added deviceId=8 to DeviceIdMap
73DEBU[0000] devmapper: Added deviceId=7 to DeviceIdMap
74DEBU[0000] devmapper: Added deviceId=10 to DeviceIdMap
75DEBU[0000] devmapper: Added deviceId=2 to DeviceIdMap
76DEBU[0000] devmapper: Added deviceId=3 to DeviceIdMap
77DEBU[0000] devmapper: Added deviceId=6 to DeviceIdMap
78DEBU[0000] devmapper: Added deviceId=13 to DeviceIdMap
79DEBU[0000] devmapper: Added deviceId=12 to DeviceIdMap
80DEBU[0000] devmapper: Added deviceId=9 to DeviceIdMap
81DEBU[0000] devmapper: Added deviceId=5 to DeviceIdMap
82DEBU[0000] devmapper: Added deviceId=11 to DeviceIdMap
83DEBU[0000] devmapper: Added deviceId=1 to DeviceIdMap
84DEBU[0000] devmapper: constructDeviceIDMap() END
85WARN[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.
86DEBU[0000] devmapper: activateDeviceIfNeeded()
87DEBU[0000] devmapper: UUID for device: /dev/mapper/docker-253:0-1573769-base is:a44e9b20-dacd-4ace-9d86-2cbef0cf7f73
88WARN[0000] devmapper: Base device already exists and has filesystem xfs on it. User specified filesystem will be ignored.
89DEBU[0000] devmapper: deactivateDevice()
90DEBU[0000] devmapper: removeDevice START(docker-253:0-1573769-base)
91DEBU[0000] devmapper: removeDevice END(docker-253:0-1573769-base)
92DEBU[0000] devmapper: deactivateDevice END()
93INFO[0000] [graphdriver] using prior storage driver "devicemapper"
94DEBU[0000] Using graph driver devicemapper
95INFO[0000] Graph migration to content-addressability took 0.00 seconds
96DEBU[0000] Option DefaultDriver: bridge
97DEBU[0000] Option DefaultNetwork: bridge
98INFO[0000] Firewalld running: false
99DEBU[0000] Registering ipam driver: "default"
100DEBU[0000] Cleaning up old shm/mqueue mounts: start.
101DEBU[0000] Cleaning up old shm/mqueue mounts: done.
102DEBU[0000] Loaded container 1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f
103DEBU[0000] Loaded container 4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161
104DEBU[0000] Loaded container aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673
105E0922 17:02:22.283233 5517 dm.go:188] losetup: /var/lib/hyper/lib/data: failed to set up loop device: Device or resource busy
106I0922 17:02:22.284660 5517 server.go:70] Server created for HTTP on unix (/var/run/hyper.sock)
107Qemu Driver Loaded
108I0922 17:02:22.285278 5517 hyperd.go:193] The hypervisor's driver is qemu
109I0922 17:02:22.285901 5517 network_linux.go:263] bridge exist
110I0922 17:02:22.289647 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -C POSTROUTING -s 192.168.123.1/24 ! -o hyper0 -j MASQUERADE]
111I0922 17:02:22.292821 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -N HYPER]
112I0922 17:02:22.294392 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o hyper0 -j HYPER]
113I0922 17:02:22.296047 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i hyper0 -j ACCEPT]
114I0922 17:02:22.297854 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o hyper0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]
115I0922 17:02:22.301514 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -N HYPER]
116I0922 17:02:22.303224 5517 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]
117I0922 17:02:22.305209 5517 iptables_linux.go:140] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j HYPER]
118I0922 17:02:22.307831 5517 daemondb.go:220] got key from leveldb pod-container-pod-evSgAursPF
119I0922 17:02:22.307863 5517 daemondb.go:220] got key from leveldb pod-container-pod-orbBigFyPD
120I0922 17:02:22.307868 5517 daemondb.go:220] got key from leveldb pod-container-pod-vQpEHWbgiu
121I0922 17:02:22.307871 5517 daemondb.go:220] got key from leveldb pod-pod-evSgAursPF
122I0922 17:02:22.307879 5517 daemondb.go:220] got key from leveldb pod-pod-orbBigFyPD
123I0922 17:02:22.307884 5517 daemondb.go:220] got key from leveldb pod-pod-vQpEHWbgiu
124I0922 17:02:22.307894 5517 daemon.go:85] reloading pod pod-evSgAursPF with args {"id":"busybox-6199998260","hostname":"","containers":[{"name":"busybox-6199998260","image":"busybox","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-evSgAursPF-resolvconf","perm":"0644","user":"","group":""}],"restartPolicy":"never"}],"resource":{"vcpu":1,"memory":128},"files":[{"name":"pod-evSgAursPF-resolvconf","encoding":"raw","uri":"file:///etc/resolv.conf","content":""}],"volumes":[{"name":"etchosts-volume","source":"/var/lib/hyper/hosts/pod-evSgAursPF/hosts","driver":"vfs","option":{"monitors":null,"user":"","keyring":"","bytespersec":0,"iops":0}}],"labels":{},"log":{"type":"json-file","config":{}},"tty":true,"type":"","RestartPolicy":""}
125I0922 17:02:22.308356 5517 run.go:40] podArgs: id:"busybox-6199998260" tty:true resource:<vcpu:1 memory:128 > log:<type:"json-file" > containers:<name:"busybox-6199998260" image:"busybox" workdir:"/" restartPolicy:"never" tty:true volumes:<path:"/etc/hosts" volume:"etchosts-volume" > files:<path:"/etc/resolv.conf" filename:"pod-evSgAursPF-resolvconf" perm:"0644" > user:<> > files:<name:"pod-evSgAursPF-resolvconf" encoding:"raw" uri:"file:///etc/resolv.conf" > volumes:<name:"etchosts-volume" source:"/var/lib/hyper/hosts/pod-evSgAursPF/hosts" driver:"vfs" option:<> >
126I0922 17:02:22.308592 5517 pod.go:905] Already has resolv.conf configured, bypass DNS insert
127I0922 17:02:22.308623 5517 daemondb.go:82] try get container list for pod pod-evSgAursPF
128I0922 17:02:22.308648 5517 pod.go:467] loaded containers for pod pod-evSgAursPF: [1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f]
129I0922 17:02:22.308660 5517 pod.go:475] Loading container 1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f of pod pod-evSgAursPF
130I0922 17:02:22.308691 5517 pod.go:487] Found exist container busybox-6199998260 (1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f), pod: pod-evSgAursPF
131I0922 17:02:22.308696 5517 pod.go:520] do not need to create container busybox-6199998260 of pod pod-evSgAursPF[0]
132I0922 17:02:22.308702 5517 pod.go:597] container name busybox-6199998260, image busybox
133I0922 17:02:22.308732 5517 pod.go:624] container info config &{1d7a3763c24d false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc8211d3b20 false busybox map[] <nil> true [] map[] }, Cmd [sh], Args []
134I0922 17:02:22.308778 5517 pod.go:648] Container Info is
135&{containerID:"1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f" commands:"sh" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474528533 b6b249718725ec9b3676a6003d4c29c37a0621d56dfb072790d0569c7fa4c08e false}
136I0922 17:02:22.308896 5517 daemondb.go:91] try set container list for pod pod-evSgAursPF: [1d7a3763c24d3f2a0b0eed89179a9753763e8c5a5523e43aa25a6ab2715ab85f]
137I0922 17:02:22.308945 5517 daemon.go:109] no existing VM for pod pod-evSgAursPF: leveldb: not found
138I0922 17:02:22.308952 5517 daemon.go:85] reloading pod pod-orbBigFyPD with args {"id":"ubuntu-7378494712","hostname":"","containers":[{"name":"ubuntu-7378494712","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-orbBigFyPD-resolvconf","perm":"0644","user":"","group":""}],"restartPolicy":"never"}],"resource":{"vcpu":1,"memory":128},"files":[{"name":"pod-orbBigFyPD-resolvconf","encoding":"raw","uri":"file:///etc/resolv.conf","content":""}],"volumes":[{"name":"etchosts-volume","source":"/var/lib/hyper/hosts/pod-orbBigFyPD/hosts","driver":"vfs","option":{"monitors":null,"user":"","keyring":"","bytespersec":0,"iops":0}}],"labels":{},"log":{"type":"json-file","config":{}},"tty":true,"type":"","RestartPolicy":""}
139I0922 17:02:22.309065 5517 run.go:40] podArgs: id:"ubuntu-7378494712" tty:true resource:<vcpu:1 memory:128 > log:<type:"json-file" > containers:<name:"ubuntu-7378494712" image:"ubuntu" workdir:"/" restartPolicy:"never" tty:true volumes:<path:"/etc/hosts" volume:"etchosts-volume" > files:<path:"/etc/resolv.conf" filename:"pod-orbBigFyPD-resolvconf" perm:"0644" > user:<> > files:<name:"pod-orbBigFyPD-resolvconf" encoding:"raw" uri:"file:///etc/resolv.conf" > volumes:<name:"etchosts-volume" source:"/var/lib/hyper/hosts/pod-orbBigFyPD/hosts" driver:"vfs" option:<> >
140I0922 17:02:22.309129 5517 pod.go:905] Already has resolv.conf configured, bypass DNS insert
141I0922 17:02:22.309154 5517 daemondb.go:82] try get container list for pod pod-orbBigFyPD
142I0922 17:02:22.309173 5517 pod.go:467] loaded containers for pod pod-orbBigFyPD: [aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673]
143I0922 17:02:22.309182 5517 pod.go:475] Loading container aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673 of pod pod-orbBigFyPD
144I0922 17:02:22.309240 5517 pod.go:487] Found exist container ubuntu-7378494712 (aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673), pod: pod-orbBigFyPD
145I0922 17:02:22.309251 5517 pod.go:520] do not need to create container ubuntu-7378494712 of pod pod-orbBigFyPD[0]
146I0922 17:02:22.309256 5517 pod.go:597] container name ubuntu-7378494712, image ubuntu
147I0922 17:02:22.309285 5517 pod.go:624] container info config &{aa8826edab7f false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc82060f3c0 false ubuntu map[] <nil> true [] map[] }, Cmd [/bin/bash], Args []
148I0922 17:02:22.309316 5517 pod.go:648] Container Info is
149&{containerID:"aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673" commands:"/bin/bash" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474529452 ba9e03dd15779eba57bf82a0cca79abcb4674c55dbb51bb1cfbb4499be316874 false}
150I0922 17:02:22.309429 5517 daemondb.go:91] try set container list for pod pod-orbBigFyPD: [aa8826edab7f53550c0e52ae0e14da73fbdef68776c3c80f05a3d97ca781d673]
151I0922 17:02:22.309487 5517 daemon.go:109] no existing VM for pod pod-orbBigFyPD: leveldb: not found
152I0922 17:02:22.309493 5517 daemon.go:85] reloading pod pod-vQpEHWbgiu with args {"id":"busybox-8936144739","hostname":"","containers":[{"name":"busybox-8936144739","image":"busybox","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-vQpEHWbgiu-resolvconf","perm":"0644","user":"","group":""}],"restartPolicy":"never"}],"resource":{"vcpu":1,"memory":128},"files":[{"name":"pod-vQpEHWbgiu-resolvconf","encoding":"raw","uri":"file:///etc/resolv.conf","content":""}],"volumes":[{"name":"etchosts-volume","source":"/var/lib/hyper/hosts/pod-vQpEHWbgiu/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":""}
153I0922 17:02:22.309604 5517 run.go:40] podArgs: id:"busybox-8936144739" tty:true labels:<key:"extra.sh.hyper.container.0.initialize" value:"yes" > resource:<vcpu:1 memory:128 > log:<> containers:<name:"busybox-8936144739" image:"busybox" workdir:"/" restartPolicy:"never" tty:true volumes:<path:"/etc/hosts" volume:"etchosts-volume" > files:<path:"/etc/resolv.conf" filename:"pod-vQpEHWbgiu-resolvconf" perm:"0644" > user:<> > files:<name:"pod-vQpEHWbgiu-resolvconf" encoding:"raw" uri:"file:///etc/resolv.conf" > volumes:<name:"etchosts-volume" source:"/var/lib/hyper/hosts/pod-vQpEHWbgiu/hosts" driver:"vfs" option:<> >
154I0922 17:02:22.309670 5517 pod.go:905] Already has resolv.conf configured, bypass DNS insert
155I0922 17:02:22.309679 5517 daemondb.go:82] try get container list for pod pod-vQpEHWbgiu
156I0922 17:02:22.309699 5517 pod.go:467] loaded containers for pod pod-vQpEHWbgiu: [4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161]
157I0922 17:02:22.309705 5517 pod.go:475] Loading container 4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161 of pod pod-vQpEHWbgiu
158I0922 17:02:22.309729 5517 pod.go:487] Found exist container busybox-8936144739 (4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161), pod: pod-vQpEHWbgiu
159I0922 17:02:22.309736 5517 pod.go:520] do not need to create container busybox-8936144739 of pod pod-vQpEHWbgiu[0]
160I0922 17:02:22.309740 5517 pod.go:597] container name busybox-8936144739, image busybox
161I0922 17:02:22.309858 5517 pod.go:624] container info config &{4e1a58cabd8f false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc82060eec0 false busybox map[] <nil> true [] map[] }, Cmd [sh], Args []
162I0922 17:02:22.309931 5517 pod.go:648] Container Info is
163&{containerID:"4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161" commands:"sh" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474533941 44d34d6d55ddefd7ef34830a749cc41810d486c026744ca27a90030986ad4cc4 true}
164I0922 17:02:22.310024 5517 daemondb.go:91] try set container list for pod pod-vQpEHWbgiu: [4e1a58cabd8f230e30cadf973988eb49648a4b18dfed367e354040a796ec1161]
165I0922 17:02:22.310124 5517 daemon.go:109] no existing VM for pod pod-vQpEHWbgiu: leveldb: not found
166I0922 17:02:22.310149 5517 daemon.go:119] 3 pod have been loaded
167I0922 17:02:22.310156 5517 daemon.go:121] container in pod pod-evSgAursPF status: [0xc82061b440]
168I0922 17:02:22.310166 5517 daemon.go:122] container in pod pod-evSgAursPF spec: [{busybox-6199998260 busybox { []} [] / [] true map[] map[] [] [] [{/etc/hosts etchosts-volume false}] [{/etc/resolv.conf pod-evSgAursPF-resolvconf 0644 }] never}]
169I0922 17:02:22.310225 5517 daemon.go:121] container in pod pod-orbBigFyPD status: [0xc82061b710]
170I0922 17:02:22.310233 5517 daemon.go:122] container in pod pod-orbBigFyPD spec: [{ubuntu-7378494712 ubuntu { []} [] / [] true map[] map[] [] [] [{/etc/hosts etchosts-volume false}] [{/etc/resolv.conf pod-orbBigFyPD-resolvconf 0644 }] never}]
171I0922 17:02:22.310249 5517 daemon.go:121] container in pod pod-vQpEHWbgiu status: [0xc82061b950]
172I0922 17:02:22.310255 5517 daemon.go:122] container in pod pod-vQpEHWbgiu spec: [{busybox-8936144739 busybox { []} [] / [] true map[] map[] [] [] [{/etc/hosts etchosts-volume false}] [{/etc/resolv.conf pod-vQpEHWbgiu-resolvconf 0644 }] never}]
173I0922 17:02:22.310851 5517 server.go:199] Registering routers
174I0922 17:02:22.311157 5517 server.go:204] Registering GET, /container/info
175I0922 17:02:22.311012 5517 hyperd.go:245] Hyper daemon: 0.6.2 0
176I0922 17:02:22.311617 5517 server.go:204] Registering GET, /container/logs
177I0922 17:02:22.311958 5517 server.go:204] Registering GET, /exitcode
178I0922 17:02:22.312181 5517 server.go:204] Registering POST, /container/create
179I0922 17:02:22.312464 5517 server.go:204] Registering POST, /container/rename
180I0922 17:02:22.312714 5517 server.go:204] Registering POST, /container/commit
181I0922 17:02:22.313002 5517 server.go:204] Registering POST, /container/stop
182I0922 17:02:22.313271 5517 server.go:204] Registering POST, /container/kill
183I0922 17:02:22.313511 5517 server.go:204] Registering POST, /exec/create
184I0922 17:02:22.313720 5517 server.go:204] Registering POST, /exec/start
185I0922 17:02:22.313931 5517 server.go:204] Registering POST, /attach
186I0922 17:02:22.314136 5517 server.go:204] Registering POST, /tty/resize
187I0922 17:02:22.314337 5517 server.go:204] Registering GET, /pod/info
188I0922 17:02:22.314542 5517 server.go:204] Registering GET, /pod/stats
189I0922 17:02:22.314807 5517 server.go:204] Registering GET, /list
190I0922 17:02:22.315180 5517 server.go:204] Registering POST, /pod/create
191I0922 17:02:22.315478 5517 server.go:204] Registering POST, /pod/labels
192I0922 17:02:22.315855 5517 server.go:204] Registering POST, /pod/start
193I0922 17:02:22.316106 5517 server.go:204] Registering POST, /pod/stop
194I0922 17:02:22.316342 5517 server.go:204] Registering POST, /pod/kill
195I0922 17:02:22.316554 5517 server.go:204] Registering POST, /pod/pause
196I0922 17:02:22.316771 5517 server.go:204] Registering POST, /pod/unpause
197I0922 17:02:22.316986 5517 server.go:204] Registering POST, /vm/create
198I0922 17:02:22.317186 5517 server.go:204] Registering DELETE, /pod
199I0922 17:02:22.317454 5517 server.go:204] Registering DELETE, /vm
200I0922 17:02:22.317674 5517 server.go:204] Registering GET, /service/list
201I0922 17:02:22.317902 5517 server.go:204] Registering POST, /service/add
202I0922 17:02:22.318124 5517 server.go:204] Registering POST, /service/update
203I0922 17:02:22.318338 5517 server.go:204] Registering DELETE, /service
204I0922 17:02:22.318567 5517 server.go:204] Registering GET, /images/get
205I0922 17:02:22.318804 5517 server.go:204] Registering POST, /image/create
206I0922 17:02:22.319011 5517 server.go:204] Registering POST, /image/load
207I0922 17:02:22.319222 5517 server.go:204] Registering POST, /image/push
208I0922 17:02:22.319445 5517 server.go:204] Registering DELETE, /image
209I0922 17:02:22.319644 5517 server.go:204] Registering GET, /_ping
210I0922 17:02:22.319877 5517 server.go:204] Registering GET, /info
211I0922 17:02:22.320171 5517 server.go:204] Registering GET, /version
212I0922 17:02:22.320485 5517 server.go:204] Registering POST, /auth
213I0922 17:02:22.320865 5517 server.go:204] Registering POST, /image/build
214I0922 17:02:22.321235 5517 server.go:95] API listen on /var/run/hyper.sock
215I0922 17:02:44.662792 5517 server.go:152] Calling POST /v0.6.2/vm/create
216I0922 17:02:44.662831 5517 vm.go:192] The config: kernel=/var/lib/hyper/kernel, initrd=/var/lib/hyper/hyper-initrd.img
217I0922 17:02:44.663509 5517 qemu_process.go:131] cmdline arguments: -machine pc-i440fx-2.0,accel=kvm,usb=off -global kvm-pit.lost_tick_policy=discard -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-iGMHsoEeXV/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-iGMHsoEeXV/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-iGMHsoEeXV/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-iGMHsoEeXV/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-iGMHsoEeXV/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir -daemonize -pidfile /var/run/hyper/vm-iGMHsoEeXV/pidfile -D /var/log/hyper/qemu/vm-iGMHsoEeXV.log
218I0922 17:02:44.663533 5517 qemu_process.go:132] qemu log file: /var/log/hyper/qemu/vm-iGMHsoEeXV.log
219I0922 17:02:44.665006 5517 server.go:152] Calling POST /v0.6.2/pod/create
220I0922 17:02:44.665091 5517 pod_routes.go:76] Args string is {"id":"busybox-7866800518","hostname":"","containers":[{"name":"busybox-7866800518","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
221I0922 17:02:44.665313 5517 run.go:40] podArgs: id:"busybox-7866800518" tty:true resource:<vcpu:1 memory:128 > log:<> containers:<name:"busybox-7866800518" image:"busybox" workdir:"/" restartPolicy:"never" user:<> >
222I0922 17:02:44.672991 5517 daemondb.go:82] try get container list for pod pod-OUfBbohkAW
223I0922 17:02:44.673027 5517 pod.go:467] loaded containers for pod pod-OUfBbohkAW: []
224DEBU[0022] devmapper: AddDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init basehash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15)
225DEBU[0022] devmapper: registerDevice(14, 9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
226DEBU[0022] devmapper: AddDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init basehash=59b902b72205af11560175bca929eb848a1aacf2f0b7b99f0dd6ceb7f4f57d15) END
227DEBU[0022] devmapper: activateDeviceIfNeeded(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
228DEBU[0022] devmapper: UnmountDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
229DEBU[0022] devmapper: Unmount(/var/lib/hyper/devicemapper/mnt/9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
230DEBU[0022] devmapper: Unmount done
231DEBU[0022] devmapper: deactivateDevice(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
232DEBU[0022] devmapper: removeDevice START(docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
233DEBU[0022] devmapper: removeDevice END(docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
234DEBU[0022] devmapper: deactivateDevice END(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
235DEBU[0022] devmapper: UnmountDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init) END
236DEBU[0022] devmapper: AddDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9 basehash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init)
237DEBU[0022] devmapper: registerDevice(15, 9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
238DEBU[0022] devmapper: AddDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9 basehash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9-init) END
239DEBU[0022] devmapper: activateDeviceIfNeeded(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
240I0922 17:02:44.785287 5517 qmp_handler.go:167] connected to /var/run/hyper/vm-iGMHsoEeXV/qmp.sock
241I0922 17:02:44.785320 5517 qmp_handler.go:177] begin qmp init...
242I0922 17:02:44.785388 5517 init_comm.go:53] connected to /var/run/hyper/vm-iGMHsoEeXV/console.sock
243I0922 17:02:44.785401 5517 init_comm.go:60] connected /var/run/hyper/vm-iGMHsoEeXV/console.sock as telnet mode.
244I0922 17:02:44.785462 5517 tty.go:155] tty socket connected
245I0922 17:02:44.785482 5517 tty.go:98] tty: trying to read 12 bytes
246I0922 17:02:44.785850 5517 init_comm.go:142] Wating for init messages...
247I0922 17:02:44.785887 5517 init_comm.go:96] trying to read 8 bytes
248DEBU[0022] container mounted via layerStore: /var/lib/hyper/devicemapper/mnt/9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9/rootfs
249DEBU[0022] devmapper: UnmountDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
250DEBU[0022] devmapper: Unmount(/var/lib/hyper/devicemapper/mnt/9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
251DEBU[0022] devmapper: Unmount done
252DEBU[0022] devmapper: deactivateDevice(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
253DEBU[0022] devmapper: removeDevice START(docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
254I0922 17:02:44.823798 5517 qmp_handler.go:186] got qmp welcome, now sending command qmp_capabilities
255I0922 17:02:44.824325 5517 qmp_handler.go:201] waiting for response
256DEBU[0022] devmapper: removeDevice END(docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
257DEBU[0022] devmapper: deactivateDevice END(9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9)
258DEBU[0022] devmapper: UnmountDevice(hash=9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9) END
259I0922 17:02:44.828573 5517 qemu_process.go:206] starting daemon with pid: 5598
260I0922 17:02:44.828622 5517 pod.go:557] create container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
261I0922 17:02:44.828686 5517 pod.go:597] container name busybox-7866800518, image busybox
262I0922 17:02:44.828730 5517 pod.go:624] container info config &{7f7b92a939a4 false false false map[] false false false [PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] 0xc8212314e0 false busybox map[] <nil> true [] map[] }, Cmd [sh], Args []
263I0922 17:02:44.828856 5517 pod.go:648] Container Info is
264&{containerID:"7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112" commands:"sh" env:<env:"PATH" value:"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin" > 1474534964 9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9 true}
265I0922 17:02:44.829151 5517 qmp_handler.go:103] got a message {"return": {}}
266I0922 17:02:44.829325 5517 qmp_handler.go:210] got for response
267I0922 17:02:44.829450 5517 qmp_handler.go:213] QMP connection initialized
268I0922 17:02:44.829626 5517 qmp_handler.go:346] QMP initialzed, go into main QMP loop
269I0922 17:02:44.829451 5517 daemondb.go:91] try set container list for pod pod-OUfBbohkAW: [7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112]
270I0922 17:02:44.830110 5517 qmp_handler.go:137] Begin receive QMP message
271I0922 17:02:44.831512 5517 server.go:152] Calling GET /v0.6.2/pod/info
272I0922 17:02:44.833132 5517 server.go:152] Calling POST /v1.17/pod/start
273I0922 17:02:44.833462 5517 run.go:68] Run pod with tty attached
274I0922 17:02:44.833475 5517 run.go:76] pod:pod-OUfBbohkAW, vm:vm-iGMHsoEeXV
275I0922 17:02:44.833814 5517 pod.go:320] lock pod pod-OUfBbohkAW for operation start
276I0922 17:02:44.834013 5517 pod.go:323] successfully lock pod pod-OUfBbohkAW for operation start
277I0922 17:02:44.834330 5517 vm.go:229] find vm:vm-iGMHsoEeXV
278I0922 17:02:44.834705 5517 pod.go:960] container ID: 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112, mountId 9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9
279I0922 17:02:44.866518 5517 dm.go:95] The filesytem type is xfs
280I0922 17:02:44.893291 5517 volumes.go:29] trying to bind dir /var/lib/hyper/hosts/pod-OUfBbohkAW/hosts to /var/run/hyper/vm-iGMHsoEeXV/share_dir/wkKhivzCxb
281I0922 17:02:44.893528 5517 storage.go:79] dir /var/lib/hyper/hosts/pod-OUfBbohkAW/hosts is bound to wkKhivzCxb
282I0922 17:02:44.893548 5517 pod.go:1119] configuring log driver [json-file] for pod-OUfBbohkAW
283I0922 17:02:44.893606 5517 pod.go:1147] configure container log to /var/run/hyper/Pods/pod-OUfBbohkAW/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112-json.log
284I0922 17:02:44.893638 5517 pod.go:1153] configured logger for pod-OUfBbohkAW/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 (/busybox-7866800518)
285I0922 17:02:44.893696 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 34(GENERIC_OPERATION)
286I0922 17:02:44.893702 5517 vm_states.go:289] handle GenericOperation(Attach) on state(INIT)
287I0922 17:02:44.893728 5517 vm_states.go:229] attachment 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 is pending
288I0922 17:02:44.893744 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 34(GENERIC_OPERATION)
289I0922 17:02:44.893747 5517 vm_states.go:289] handle GenericOperation(Attach) on state(INIT)
290I0922 17:02:44.893749 5517 vm_states.go:229] attachment 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 is pending
291I0922 17:02:44.893753 5517 pod.go:1205] Attach to container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 before start pod
292I0922 17:02:44.893775 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 21(COMMAND_RUN_POD)
293I0922 17:02:44.893779 5517 vm_states.go:439] got spec, prepare devices
294I0922 17:02:44.893789 5517 context.go:292] #0 Container Info:
295I0922 17:02:44.893879 5517 vm.go:162] hyperHandlePodEvent pod pod-OUfBbohkAW, vm vm-iGMHsoEeXV
296I0922 17:02:44.893939 5517 context.go:295]
297{
298...| "Id": "7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112",
299...| "User": "",
300...| "MountId": "9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9",
301...| "Rootfs": "/rootfs",
302...| "Image": {
303...| "name": "",
304...| "source": "/dev/mapper/docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9",
305...| "driver": "",
306...| "option": {
307...| "monitors": null,
308...| "user": "",
309...| "keyring": "",
310...| "bytespersec": 0,
311...| "iops": 0
312...| }
313...| },
314...| "Fstype": "xfs",
315...| "Workdir": "",
316...| "Entrypoint": null,
317...| "Cmd": [
318...| "sh"
319...| ],
320...| "Envs": {
321...| "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
322...| },
323...| "Initialize": true
324...|}
325I0922 17:02:44.893970 5517 devicemap.go:196] insert volume /dev/mapper/docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9 source /dev/mapper/docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9 fstype xfs
326I0922 17:02:44.893989 5517 devicemap.go:281] insert volume etchosts-volume to /etc/hosts on 0
327I0922 17:02:44.894156 5517 vm_states.go:67] initial vm spec: {
328 "hostname": "busybox-7866800518",
329 "containers": [
330 {
331 "id": "7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112",
332 "rootfs": "/rootfs",
333 "fstype": "xfs",
334 "image": "",
335 "fsmap": [
336 {
337 "source": "wkKhivzCxb",
338 "path": "/etc/hosts",
339 "readOnly": false,
340 "dockerVolume": false
341 }
342 ],
343 "process": {
344 "terminal": true,
345 "stdio": 1,
346 "args": [
347 "sh"
348 ],
349 "envs": [
350 {
351 "env": "PATH",
352 "value": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
353 }
354 ],
355 "workdir": "/"
356 },
357 "restartPolicy": "never",
358 "initialize": true
359 }
360 ],
361 "shareDir": "share_dir"
362 }
363I0922 17:02:44.894172 5517 context.go:224] found container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 at 0
364I0922 17:02:44.894178 5517 vm_states.go:75] attach pending client for 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
365I0922 17:02:44.894183 5517 vm_states.go:247] Connecting tty for 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 on session 1
366I0922 17:02:44.894186 5517 context.go:224] found container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 at 0
367I0922 17:02:44.894189 5517 vm_states.go:75] attach pending client for 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
368I0922 17:02:44.894191 5517 vm_states.go:247] Connecting tty for 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 on session 1
369I0922 17:02:44.894216 5517 context.go:260] VM vm-iGMHsoEeXV: state change from INIT to 'STARTING'
370I0922 17:02:44.894223 5517 qmp_handler.go:296] got new session
371I0922 17:02:44.894234 5517 qmp_handler.go:225] Begin process command session
372I0922 17:02:44.894245 5517 qmp_handler.go:243] sending command (1) {"execute":"human-monitor-command","arguments":{"command-line":"drive_add dummy file=/dev/mapper/docker-253:0-1573769-9db455a28c794fff5c34b608197b14df5ca794e289c15d9dab6722bf7b716de9,if=none,id=drive0,format=raw,cache=writeback"}}
373I0922 17:02:44.897538 5517 qmp_handler.go:103] got a message {"return": "OK\r\n"}
374I0922 17:02:44.898005 5517 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"}}
375I0922 17:02:44.900956 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 12(EVENT_INTERFACE_ADD)
376I0922 17:02:44.901174 5517 qmp_wrapper_amd64.go:17] send net to qemu at 30
377I0922 17:02:44.901335 5517 qmp_handler.go:296] got new session
378I0922 17:02:44.907615 5517 qmp_handler.go:103] got a message {"return": {}}
379I0922 17:02:44.907664 5517 qmp_handler.go:302] session finished, buffer size 2
380I0922 17:02:44.907672 5517 qmp_handler.go:305] success
381I0922 17:02:44.907688 5517 qmp_handler.go:225] Begin process command session
382I0922 17:02:44.907704 5517 qmp_handler.go:238] send cmd with scm (24 bytes) (1) {"execute":"getfd","arguments":{"fdname":"fdeth0"}}
383I0922 17:02:44.907723 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 9(EVENT_BLOCK_INSERTED)
384I0922 17:02:44.908219 5517 qmp_handler.go:103] got a message {"return": {}}
385I0922 17:02:44.908394 5517 qmp_handler.go:243] sending command (1) {"execute":"netdev_add","arguments":{"fd":"fdeth0","id":"eth0","type":"tap"}}
386I0922 17:02:44.909383 5517 qmp_handler.go:103] got a message {"return": {}}
387I0922 17:02:44.909754 5517 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:de:2a:01:63","netdev":"eth0"}}
388I0922 17:02:44.914157 5517 qmp_handler.go:103] got a message {"return": {}}
389I0922 17:02:44.914417 5517 qmp_handler.go:302] session finished, buffer size 1
390I0922 17:02:44.914435 5517 qmp_handler.go:305] success
391I0922 17:02:44.914443 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 14(EVENT_INTERFACE_INSERTED)
392I0922 17:02:44.914455 5517 vm_states.go:466] device ready, could run pod.
393I0922 17:02:46.249473 5517 init_comm.go:68] [console] Initializing cgroup subsys cpuset
394I0922 17:02:46.250741 5517 init_comm.go:68] [console] Initializing cgroup subsys cpu
395I0922 17:02:46.252208 5517 init_comm.go:68] [console] Initializing cgroup subsys cpuacct
396I0922 17:02:46.257226 5517 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
397I0922 17:02:46.259275 5517 init_comm.go:68] [console] Command line: console=ttyS0 panic=1 no_timer_check
398I0922 17:02:46.260713 5517 init_comm.go:68] [console] x86/fpu: Legacy x87 FPU detected.
399I0922 17:02:46.262453 5517 init_comm.go:68] [console] x86/fpu: Using 'lazy' FPU context switches.
400I0922 17:02:46.263914 5517 init_comm.go:68] [console] e820: BIOS-provided physical RAM map:
401I0922 17:02:46.266441 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
402I0922 17:02:46.268701 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
403I0922 17:02:46.271432 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
404I0922 17:02:46.274237 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffbfff] usable
405I0922 17:02:46.276784 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x0000000007ffc000-0x0000000007ffffff] reserved
406I0922 17:02:46.278974 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
407I0922 17:02:46.281336 5517 init_comm.go:68] [console] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
408I0922 17:02:46.282742 5517 init_comm.go:68] [console] NX (Execute Disable) protection: active
409I0922 17:02:46.283535 5517 init_comm.go:68] [console] SMBIOS 2.4 present.
410I0922 17:02:46.284520 5517 init_comm.go:68] [console] Hypervisor detected: KVM
411I0922 17:02:46.286809 5517 init_comm.go:68] [console] e820: last_pfn = 0x7ffc max_arch_pfn = 0x400000000
412I0922 17:02:46.289192 5517 init_comm.go:68] [console] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT
413I0922 17:02:46.292058 5517 init_comm.go:68] [console] found SMP MP-table at [mem 0x000f6b90-0x000f6b9f] mapped at [ffff8800000f6b90]
414I0922 17:02:46.293568 5517 init_comm.go:68] [console] RAMDISK: [mem 0x07b14000-0x07feffff]
415I0922 17:02:46.295014 5517 init_comm.go:68] [console] ACPI: Early table checksum verification disabled
416I0922 17:02:46.297079 5517 init_comm.go:68] [console] ACPI: RSDP 0x00000000000F6A10 000014 (v00 BOCHS )
417I0922 17:02:46.300241 5517 init_comm.go:68] [console] ACPI: RSDT 0x0000000007FFF6D8 00002C (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
418I0922 17:02:46.303192 5517 init_comm.go:68] [console] ACPI: FACP 0x0000000007FFF5EC 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
419I0922 17:02:46.309412 5517 init_comm.go:68] [console] ACPI: DSDT 0x0000000007FFE040 0015AC (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
420I0922 17:02:46.311524 5517 init_comm.go:68] [console] ACPI: FACS 0x0000000007FFE000 000040
421I0922 17:02:46.314808 5517 init_comm.go:68] [console] ACPI: APIC 0x0000000007FFF660 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
422I0922 17:02:46.315762 5517 init_comm.go:68] [console] No NUMA configuration found
423I0922 17:02:46.317988 5517 init_comm.go:68] [console] Faking a node at [mem 0x0000000000000000-0x0000000007ffbfff]
424I0922 17:02:46.320612 5517 init_comm.go:68] [console] NODE_DATA(0) allocated [mem 0x07b02000-0x07b13fff]
425I0922 17:02:46.321851 5517 init_comm.go:68] [console] kvm-clock: Using msrs 4b564d01 and 4b564d00
426I0922 17:02:46.324214 5517 init_comm.go:68] [console] kvm-clock: cpu 0, msr 0:7ffb001, primary cpu clock
427I0922 17:02:46.326382 5517 init_comm.go:68] [console] kvm-clock: using sched offset of 1418121274 cycles
428I0922 17:02:46.330294 5517 init_comm.go:68] [console] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
429I0922 17:02:46.331040 5517 init_comm.go:68] [console] Zone ranges:
430I0922 17:02:46.332611 5517 init_comm.go:68] [console] DMA [mem 0x0000000000001000-0x0000000000ffffff]
431I0922 17:02:46.334557 5517 init_comm.go:68] [console] DMA32 [mem 0x0000000001000000-0x0000000007ffbfff]
432I0922 17:02:46.335191 5517 init_comm.go:68] [console] Normal empty
433I0922 17:02:46.336465 5517 init_comm.go:68] [console] Movable zone start for each node
434I0922 17:02:46.337522 5517 init_comm.go:68] [console] Early memory node ranges
435I0922 17:02:46.339597 5517 init_comm.go:68] [console] node 0: [mem 0x0000000000001000-0x000000000009efff]
436I0922 17:02:46.341920 5517 init_comm.go:68] [console] node 0: [mem 0x0000000000100000-0x0000000007ffbfff]
437I0922 17:02:46.345208 5517 init_comm.go:68] [console] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffbfff]
438I0922 17:02:46.346328 5517 init_comm.go:68] [console] ACPI: PM-Timer IO Port: 0x608
439I0922 17:02:46.348173 5517 init_comm.go:68] [console] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
440I0922 17:02:46.350323 5517 init_comm.go:68] [console] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
441I0922 17:02:46.352917 5517 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
442I0922 17:02:46.355257 5517 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
443I0922 17:02:46.357139 5517 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
444I0922 17:02:46.359393 5517 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
445I0922 17:02:46.361853 5517 init_comm.go:68] [console] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
446I0922 17:02:46.363265 5517 init_comm.go:68] [console] Using ACPI (MADT) for SMP configuration information
447I0922 17:02:46.365019 5517 init_comm.go:68] [console] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
448I0922 17:02:46.366970 5517 init_comm.go:68] [console] e820: [mem 0x08000000-0xfeffbfff] available for PCI devices
449I0922 17:02:46.368489 5517 init_comm.go:68] [console] Booting paravirtualized kernel on KVM
450I0922 17:02:46.375963 5517 init_comm.go:68] [console] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
451I0922 17:02:46.380663 5517 init_comm.go:68] [console] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_ids:1
452I0922 17:02:46.384496 5517 init_comm.go:68] [console] PERCPU: Embedded 31 pages/cpu @ffff880007800000 s89624 r8192 d29160 u2097152
453I0922 17:02:46.386727 5517 init_comm.go:68] [console] KVM setup async PF for cpu 0
454I0922 17:02:46.388622 5517 init_comm.go:68] [console] kvm-stealtime: cpu 0, msr 780d480
455I0922 17:02:46.391990 5517 init_comm.go:68] [console] Built 1 zonelists in Node order, mobility grouping on. Total pages: 32133
456I0922 17:02:46.392781 5517 init_comm.go:68] [console] Policy zone: DMA32
457I0922 17:02:46.394439 5517 init_comm.go:68] [console] Kernel command line: console=ttyS0 panic=1 no_timer_check
458I0922 17:02:46.396360 5517 init_comm.go:68] [console] PID hash table entries: 512 (order: 0, 4096 bytes)
459I0922 17:02:46.400713 5517 init_comm.go:68] [console] Memory: 114748K/130664K available (4658K kernel code, 576K rwdata, 1472K rodata, 876K init, 756K bss, 15916K reserved, 0K cma-reserved)
460I0922 17:02:46.402337 5517 init_comm.go:68] [console] Hierarchical RCU implementation.
461I0922 17:02:46.404245 5517 init_comm.go:68] [console] Build-time adjustment of leaf fanout to 64.
462I0922 17:02:46.406379 5517 init_comm.go:68] [console] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=1.
463I0922 17:02:46.408673 5517 init_comm.go:68] [console] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
464I0922 17:02:46.409989 5517 init_comm.go:68] [console] NR_IRQS:4352 nr_irqs:256 16
465I0922 17:02:46.411426 5517 init_comm.go:68] [console] Console: colour *CGA 80x25
466I0922 17:02:46.412398 5517 init_comm.go:68] [console] console [ttyS0] enabled
467I0922 17:02:46.414170 5517 init_comm.go:68] [console] tsc: Detected 2494.302 MHz processor
468I0922 17:02:46.419185 5517 init_comm.go:68] [console] Calibrating delay loop (skipped) preset value.. 4988.60 BogoMIPS (lpj=2494302)
469I0922 17:02:46.420625 5517 init_comm.go:68] [console] pid_max: default: 32768 minimum: 301
470I0922 17:02:46.421809 5517 init_comm.go:68] [console] ACPI: Core revision 20150930
471I0922 17:02:46.424338 5517 init_comm.go:68] [console] ACPI: 1 ACPI AML tables successfully acquired and loaded
472I0922 17:02:46.427152 5517 init_comm.go:68] [console] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes)
473I0922 17:02:46.429708 5517 init_comm.go:68] [console] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
474I0922 17:02:46.431814 5517 init_comm.go:68] [console] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
475I0922 17:02:46.433977 5517 init_comm.go:68] [console] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
476I0922 17:02:46.435503 5517 init_comm.go:68] [console] Initializing cgroup subsys io
477I0922 17:02:46.437105 5517 init_comm.go:68] [console] Initializing cgroup subsys memory
478I0922 17:02:46.439366 5517 init_comm.go:68] [console] Initializing cgroup subsys devices
479I0922 17:02:46.440887 5517 init_comm.go:68] [console] Initializing cgroup subsys freezer
480I0922 17:02:46.443692 5517 init_comm.go:68] [console] Initializing cgroup subsys net_cls
481I0922 17:02:46.445377 5517 init_comm.go:68] [console] Initializing cgroup subsys perf_event
482I0922 17:02:46.446889 5517 init_comm.go:68] [console] Initializing cgroup subsys net_prio
483I0922 17:02:46.447976 5517 init_comm.go:68] [console] Initializing cgroup subsys pids
484I0922 17:02:46.449278 5517 init_comm.go:68] [console] Initializing cgroup subsys debug
485I0922 17:02:46.451230 5517 init_comm.go:68] [console] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
486I0922 17:02:46.453969 5517 init_comm.go:68] [console] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
487I0922 17:02:46.494831 5517 init_comm.go:68] [console] Freeing SMP alternatives memory: 20K (ffffffff8176b000 - ffffffff81770000)
488I0922 17:02:46.515627 5517 init_comm.go:68] [console] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
489I0922 17:02:46.622681 5517 init_comm.go:68] [console] smpboot: CPU0: Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz (family: 0x6, model: 0xf, stepping: 0xb)
490I0922 17:02:46.627307 5517 init_comm.go:68] [console] Performance Events: unsupported p6 CPU model 15 no PMU driver, software events only.
491I0922 17:02:46.628743 5517 init_comm.go:68] [console] x86: Booted up 1 node, 1 CPUs
492I0922 17:02:46.631185 5517 init_comm.go:68] [console] smpboot: Total of 1 processors activated (4988.60 BogoMIPS)
493I0922 17:02:46.632838 5517 init_comm.go:68] [console] devtmpfs: initialized
494I0922 17:02:46.637439 5517 init_comm.go:68] [console] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
495I0922 17:02:46.639039 5517 init_comm.go:68] [console] NET: Registered protocol family 16
496I0922 17:02:46.641184 5517 init_comm.go:68] [console] cpuidle: using governor ladder
497I0922 17:02:46.642553 5517 init_comm.go:68] [console] cpuidle: using governor menu
498I0922 17:02:46.644687 5517 init_comm.go:68] [console] ACPI: bus type PCI registered
499I0922 17:02:46.647175 5517 init_comm.go:68] [console] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
500I0922 17:02:46.648820 5517 init_comm.go:68] [console] PCI: Using configuration type 1 for base access
501I0922 17:02:46.650690 5517 init_comm.go:68] [console] ACPI: Added _OSI(Module Device)
502I0922 17:02:46.651826 5517 init_comm.go:68] [console] ACPI: Added _OSI(Processor Device)
503I0922 17:02:46.653956 5517 init_comm.go:68] [console] ACPI: Added _OSI(3.0 _SCP Extensions)
504I0922 17:02:46.655563 5517 init_comm.go:68] [console] ACPI: Added _OSI(Processor Aggregator Device)
505I0922 17:02:46.658498 5517 init_comm.go:68] [console] ACPI: Interpreter enabled
506I0922 17:02:46.659438 5517 init_comm.go:68] [console] ACPI: (supports S0 S5)
507I0922 17:02:46.660748 5517 init_comm.go:68] [console] ACPI: Using IOAPIC for interrupt routing
508I0922 17:02:46.663760 5517 init_comm.go:68] [console] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
509I0922 17:02:46.667774 5517 init_comm.go:68] [console] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
510I0922 17:02:46.669743 5517 init_comm.go:68] [console] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
511I0922 17:02:46.673949 5517 init_comm.go:68] [console] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
512I0922 17:02:46.676230 5517 init_comm.go:68] [console] acpiphp: Slot [2] registered
513I0922 17:02:46.679157 5517 init_comm.go:68] [console] acpiphp: Slot [3] registered
514I0922 17:02:46.680466 5517 init_comm.go:68] [console] acpiphp: Slot [4] registered
515I0922 17:02:46.681604 5517 init_comm.go:68] [console] acpiphp: Slot [5] registered
516I0922 17:02:46.682827 5517 init_comm.go:68] [console] acpiphp: Slot [6] registered
517I0922 17:02:46.685773 5517 init_comm.go:68] [console] acpiphp: Slot [7] registered
518I0922 17:02:46.687870 5517 init_comm.go:68] [console] acpiphp: Slot [8] registered
519I0922 17:02:46.690020 5517 init_comm.go:68] [console] acpiphp: Slot [9] registered
520I0922 17:02:46.692071 5517 init_comm.go:68] [console] acpiphp: Slot [10] registered
521I0922 17:02:46.693742 5517 init_comm.go:68] [console] acpiphp: Slot [11] registered
522I0922 17:02:46.695639 5517 init_comm.go:68] [console] acpiphp: Slot [12] registered
523I0922 17:02:46.697006 5517 init_comm.go:68] [console] acpiphp: Slot [13] registered
524I0922 17:02:46.698377 5517 init_comm.go:68] [console] acpiphp: Slot [14] registered
525I0922 17:02:46.699651 5517 init_comm.go:68] [console] acpiphp: Slot [15] registered
526I0922 17:02:46.700927 5517 init_comm.go:68] [console] acpiphp: Slot [16] registered
527I0922 17:02:46.701979 5517 init_comm.go:68] [console] acpiphp: Slot [17] registered
528I0922 17:02:46.703301 5517 init_comm.go:68] [console] acpiphp: Slot [18] registered
529I0922 17:02:46.705265 5517 init_comm.go:68] [console] acpiphp: Slot [19] registered
530I0922 17:02:46.708328 5517 init_comm.go:68] [console] acpiphp: Slot [20] registered
531I0922 17:02:46.711081 5517 init_comm.go:68] [console] acpiphp: Slot [21] registered
532I0922 17:02:46.712198 5517 init_comm.go:68] [console] acpiphp: Slot [22] registered
533I0922 17:02:46.713499 5517 init_comm.go:68] [console] acpiphp: Slot [23] registered
534I0922 17:02:46.714624 5517 init_comm.go:68] [console] acpiphp: Slot [24] registered
535I0922 17:02:46.715958 5517 init_comm.go:68] [console] acpiphp: Slot [25] registered
536I0922 17:02:46.717116 5517 init_comm.go:68] [console] acpiphp: Slot [26] registered
537I0922 17:02:46.718412 5517 init_comm.go:68] [console] acpiphp: Slot [27] registered
538I0922 17:02:46.720094 5517 init_comm.go:68] [console] acpiphp: Slot [28] registered
539I0922 17:02:46.721341 5517 init_comm.go:68] [console] acpiphp: Slot [29] registered
540I0922 17:02:46.722687 5517 init_comm.go:68] [console] acpiphp: Slot [30] registered
541I0922 17:02:46.723847 5517 init_comm.go:68] [console] acpiphp: Slot [31] registered
542I0922 17:02:46.725391 5517 init_comm.go:68] [console] PCI host bridge to bus 0000:00
543I0922 17:02:46.727278 5517 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
544I0922 17:02:46.729718 5517 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
545I0922 17:02:46.731885 5517 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
546I0922 17:02:46.734423 5517 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [mem 0x08000000-0xfebfffff window]
547I0922 17:02:46.736285 5517 init_comm.go:68] [console] pci_bus 0000:00: root bus resource [bus 00-ff]
548I0922 17:02:46.749930 5517 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
549I0922 17:02:46.753529 5517 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
550I0922 17:02:46.755892 5517 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
551I0922 17:02:46.757691 5517 init_comm.go:68] [console] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
552I0922 17:02:46.761636 5517 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
553I0922 17:02:46.764213 5517 init_comm.go:68] [console] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
554I0922 17:02:46.800747 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
555I0922 17:02:46.806388 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
556I0922 17:02:46.810854 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
557I0922 17:02:46.812962 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
558I0922 17:02:46.814834 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
559I0922 17:02:46.816899 5517 init_comm.go:68] [console] ACPI: Enabled 16 GPEs in block 00 to 0F
560I0922 17:02:46.817699 5517 init_comm.go:68] [console] vgaarb: loaded
561I0922 17:02:46.819308 5517 init_comm.go:68] [console] SCSI subsystem initialized
562I0922 17:02:46.820847 5517 init_comm.go:68] [console] PCI: Using ACPI for IRQ routing
563I0922 17:02:46.822898 5517 init_comm.go:68] [console] clocksource: Switched to clocksource kvm-clock
564I0922 17:02:46.824477 5517 init_comm.go:68] [console] pnp: PnP ACPI init
565I0922 17:02:46.826156 5517 init_comm.go:68] [console] pnp: PnP ACPI: found 5 devices
566I0922 17:02:46.835380 5517 init_comm.go:68] [console] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
567I0922 17:02:46.840085 5517 init_comm.go:68] [console] pci 0000:00:05.0: BAR 6: assigned [mem 0x08000000-0x0803ffff pref]
568I0922 17:02:46.841983 5517 init_comm.go:68] [console] pci 0000:00:05.0: BAR 1: assigned [mem 0x08040000-0x08040fff]
569I0922 17:02:46.844976 5517 init_comm.go:68] [console] pci 0000:00:05.0: BAR 0: assigned [io 0x1000-0x101f]
570I0922 17:02:46.846318 5517 init_comm.go:68] [console] NET: Registered protocol family 2
571I0922 17:02:46.849230 5517 init_comm.go:68] [console] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
572I0922 17:02:46.853217 5517 init_comm.go:68] [console] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
573I0922 17:02:46.857200 5517 init_comm.go:68] [console] TCP: Hash tables configured (established 1024 bind 1024)
574I0922 17:02:46.859332 5517 init_comm.go:68] [console] UDP hash table entries: 256 (order: 1, 8192 bytes)
575I0922 17:02:46.861694 5517 init_comm.go:68] [console] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
576I0922 17:02:46.864243 5517 init_comm.go:68] [console] NET: Registered protocol family 1
577I0922 17:02:46.867116 5517 init_comm.go:68] [console] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
578I0922 17:02:46.869715 5517 init_comm.go:68] [console] pci 0000:00:01.0: PIIX3: Enabling Passive Release
579I0922 17:02:46.872384 5517 init_comm.go:68] [console] pci 0000:00:01.0: Activating ISA DMA hang workarounds
580I0922 17:02:46.874478 5517 init_comm.go:68] [console] Trying to unpack rootfs image as initramfs...
581I0922 17:02:46.944957 5517 init_comm.go:68] [console] Freeing initrd memory: 4976K (ffff880007b14000 - ffff880007ff0000)
582I0922 17:02:46.947526 5517 init_comm.go:68] [console] futex hash table entries: 256 (order: 2, 16384 bytes)
583I0922 17:02:46.949768 5517 init_comm.go:68] [console] SGI XFS with ACLs, security attributes, no debug enabled
584I0922 17:02:46.952063 5517 init_comm.go:68] [console] 9p: Installing v9fs 9p2000 file system support
585I0922 17:02:46.955371 5517 init_comm.go:68] [console] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
586I0922 17:02:46.956563 5517 init_comm.go:68] [console] io scheduler noop registered
587I0922 17:02:46.957885 5517 init_comm.go:68] [console] io scheduler cfq registered (default)
588I0922 17:02:46.959778 5517 init_comm.go:68] [console] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
589I0922 17:02:46.961713 5517 init_comm.go:68] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
590I0922 17:02:46.964316 5517 init_comm.go:68] [console] Warning: Processor Platform Limit event detected, but not handled.
591I0922 17:02:46.966488 5517 init_comm.go:68] [console] Consider compiling CPUfreq support into your kernel.
592I0922 17:02:46.986311 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
593I0922 17:02:46.988829 5517 init_comm.go:68] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
594I0922 17:02:47.011645 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
595I0922 17:02:47.016475 5517 init_comm.go:68] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
596I0922 17:02:47.041205 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
597I0922 17:02:47.045033 5517 init_comm.go:68] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
598I0922 17:02:47.047703 5517 init_comm.go:68] [console] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)
599I0922 17:02:47.069562 5517 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
600I0922 17:02:47.073845 5517 init_comm.go:68] [console] virtio-pci 0000:00:05.0: virtio_pci: leaving for legacy driver
601I0922 17:02:47.078603 5517 init_comm.go:68] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
602I0922 17:02:47.107003 5517 init_comm.go:68] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
603I0922 17:02:47.119926 5517 init_comm.go:68] [console] brd: module loaded
604I0922 17:02:47.120708 5517 init_comm.go:68] [console] loop: module loaded
605I0922 17:02:47.123434 5517 init_comm.go:68] [console] scsi host0: Virtio SCSI HBA
606I0922 17:02:47.126812 5517 init_comm.go:68] [console] scsi 0:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.0. PQ: 0 ANSI: 5
607I0922 17:02:47.154983 5517 init_comm.go:68] [console] sd 0:0:0:0: Attached scsi generic sg0 type 0
608I0922 17:02:47.157831 5517 init_comm.go:68] [console] rtc_cmos 00:00: RTC can wake from S4
609I0922 17:02:47.160361 5517 init_comm.go:68] [console] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
610I0922 17:02:47.163451 5517 init_comm.go:68] [console] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram
611I0922 17:02:47.164839 5517 init_comm.go:68] [console] Initializing XFRM netlink socket
612I0922 17:02:47.166245 5517 init_comm.go:68] [console] NET: Registered protocol family 10
613I0922 17:02:47.167901 5517 init_comm.go:68] [console] NET: Registered protocol family 17
614I0922 17:02:47.171785 5517 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.
615I0922 17:02:47.173190 5517 init_comm.go:68] [console] Bridge firewalling registered
616I0922 17:02:47.174591 5517 init_comm.go:68] [console] 9pnet: Installing 9P2000 support
617I0922 17:02:47.179835 5517 init_comm.go:68] [console] sd 0:0:0:0: [sda] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
618I0922 17:02:47.181451 5517 init_comm.go:68] [console] registered taskstats version 1
619I0922 17:02:47.186216 5517 init_comm.go:68] [console] rtc_cmos 00:00: setting system clock to 2016-09-22 09:02:46 UTC (1474534966)
620I0922 17:02:47.188745 5517 init_comm.go:68] [console] sd 0:0:0:0: [sda] Write Protect is off
621I0922 17:02:47.192195 5517 init_comm.go:68] [console] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
622I0922 17:02:47.195038 5517 init_comm.go:68] [console] sd 0:0:0:0: [sda] Attached SCSI disk
623I0922 17:02:47.198047 5517 init_comm.go:68] [console] Freeing unused kernel memory: 876K (ffffffff81690000 - ffffffff8176b000)
624I0922 17:02:47.199045 5517 init_comm.go:68] [console] create directory /sys
625I0922 17:02:47.199964 5517 init_comm.go:68] [console] create directory /sbin
626I0922 17:02:47.200711 5517 init_comm.go:68] [console] create directory /proc
627I0922 17:02:47.201325 5517 init_comm.go:68] [console] uptime 0.59 0.07
628I0922 17:02:47.201638 5517 init_comm.go:68] [console]
629I0922 17:02:47.202910 5517 init_comm.go:68] [console] create directory /dev/pts
630I0922 17:02:47.205044 5517 init_comm.go:68] [console] open hyper channel /dev/vport0p1
631I0922 17:02:47.205609 5517 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1474534967, "microseconds": 205494}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel0"}}
632I0922 17:02:47.205848 5517 qmp_handler.go:107] got event: VSERPORT_CHANGE
633I0922 17:02:47.206166 5517 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
634I0922 17:02:47.206482 5517 init_comm.go:68] [console] send ready message
635I0922 17:02:47.208211 5517 init_comm.go:68] [console] hyper send type 8, len 0
636I0922 17:02:47.208858 5517 init_comm.go:106] read 8/8 [length = 0]
637I0922 17:02:47.208900 5517 init_comm.go:110] data length is 8
638I0922 17:02:47.208911 5517 init_comm.go:152] Get init ready message
639I0922 17:02:47.208971 5517 init_comm.go:225] got cmd:1
640I0922 17:02:47.209067 5517 init_comm.go:316] send command 1 to init, payload: '{"hostname":"busybox-7866800518","containers":[{"id":"7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112","rootfs":"/rootfs","fstype":"xfs","image":"sda","fsmap":[{"source":"wkKhivzCxb","path":"/etc/hosts","readOnly":false,"dockerVolume":false}],"process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"}],"workdir":"/"},"restartPolicy":"never","initialize":true}],"interfaces":[{"device":"eth0","ipAddress":"192.168.123.2","netMask":"255.255.255.0"}],"routes":[{"dest":"0.0.0.0/0","gateway":"192.168.123.1","device":"eth0"}],"shareDir":"share_dir"}'.
641I0922 17:02:47.209100 5517 init_comm.go:329] write 512 to init, payload: '�{"hostname":"busybox-7866800518","containers":[{"id":"7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112","rootfs":"/rootfs","fstype":"xfs","image":"sda","fsmap":[{"source":"wkKhivzCxb","path":"/etc/hosts","readOnly":false,"dockerVolume":false}],"process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"}],"workdir":"/"},"restartPolicy":"never","initialize":true}],"interfaces":[{"device":"eth0","ipAddre'.
642I0922 17:02:47.209109 5517 init_comm.go:334] message sent, set pong timer
643I0922 17:02:47.209116 5517 init_comm.go:225] got cmd:0
644I0922 17:02:47.209121 5517 init_comm.go:316] send command 0 to init, payload: 'null'.
645I0922 17:02:47.209129 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 5(EVENT_INIT_CONNECTED)
646I0922 17:02:47.209138 5517 vm_states.go:480] begin to wait vm commands
647I0922 17:02:47.209155 5517 init_comm.go:96] trying to read 8 bytes
648I0922 17:02:47.209163 5517 vm.go:275] Get the response from VM, VM id is vm-iGMHsoEeXV!
649I0922 17:02:47.211476 5517 init_comm.go:68] [console] channel sh.hyper.channel.1, directory sh.hyper.channel.0
650I0922 17:02:47.211728 5517 init_comm.go:68] [console]
651I0922 17:02:47.212965 5517 init_comm.go:68] [console] open hyper channel /dev/vport0p2
652I0922 17:02:47.213375 5517 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1474534967, "microseconds": 213250}, "event": "VSERPORT_CHANGE", "data": {"open": true, "id": "channel1"}}
653I0922 17:02:47.213601 5517 qmp_handler.go:107] got event: VSERPORT_CHANGE
654I0922 17:02:47.213902 5517 qmp_handler.go:323] got QMP event VSERPORT_CHANGE
655I0922 17:02:47.214682 5517 init_comm.go:68] [console] hyper_init_event hyper channel event 0x61c600, ops 0x61c3e0, fd 3
656I0922 17:02:47.216061 5517 init_comm.go:68] [console] hyper_add_event add event fd 3, 0x61c3e0
657I0922 17:02:47.217615 5517 init_comm.go:68] [console] hyper_init_event hyper ttyfd event 0x61c5c8, ops 0x61c3a0, fd 4
658I0922 17:02:47.219791 5517 init_comm.go:68] [console] hyper_add_event add event fd 4, 0x61c3a0
659I0922 17:02:47.220607 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
660I0922 17:02:47.222078 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c600, fd 3. ops 0x61c3e0
661I0922 17:02:47.224060 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c600, fd 3, 0x61c3e0
662I0922 17:02:47.224694 5517 init_comm.go:68] [console] hyper_event_read
663I0922 17:02:47.225668 5517 init_comm.go:68] [console] already read 8 bytes data
664I0922 17:02:47.226504 5517 init_comm.go:68] [console] hyper send type 14, len 4
665I0922 17:02:47.226721 5517 init_comm.go:106] read 8/8 [length = 0]
666I0922 17:02:47.226735 5517 init_comm.go:110] data length is 12
667I0922 17:02:47.226739 5517 init_comm.go:96] trying to read 4 bytes
668I0922 17:02:47.226743 5517 init_comm.go:106] read 12/12 [length = 12]
669I0922 17:02:47.226754 5517 init_comm.go:96] trying to read 8 bytes
670I0922 17:02:47.226764 5517 init_comm.go:225] got cmd:14
671I0922 17:02:47.226768 5517 init_comm.go:288] get command NEXT
672I0922 17:02:47.226772 5517 init_comm.go:291] send 512, receive 8
673I0922 17:02:47.227184 5517 init_comm.go:68] [console] get length 657
674I0922 17:02:47.228085 5517 init_comm.go:68] [console] read 504 bytes data, total data 512
675I0922 17:02:47.228882 5517 init_comm.go:68] [console] hyper send type 14, len 4
676I0922 17:02:47.229070 5517 init_comm.go:106] read 8/8 [length = 0]
677I0922 17:02:47.229221 5517 init_comm.go:110] data length is 12
678I0922 17:02:47.229427 5517 init_comm.go:96] trying to read 4 bytes
679I0922 17:02:47.229582 5517 init_comm.go:106] read 12/12 [length = 12]
680I0922 17:02:47.229713 5517 init_comm.go:96] trying to read 8 bytes
681I0922 17:02:47.229855 5517 init_comm.go:225] got cmd:14
682I0922 17:02:47.229997 5517 init_comm.go:288] get command NEXT
683I0922 17:02:47.230128 5517 init_comm.go:291] send 512, receive 512
684I0922 17:02:47.230273 5517 init_comm.go:329] write 157 to init, payload: 'ss":"192.168.123.2","netMask":"255.255.255.0"}],"routes":[{"dest":"0.0.0.0/0","gateway":"192.168.123.1","device":"eth0"}],"shareDir":"share_dir"}
685 null'.
686I0922 17:02:47.231023 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
687I0922 17:02:47.232366 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c600, fd 3. ops 0x61c3e0
688I0922 17:02:47.233783 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c600, fd 3, 0x61c3e0
689I0922 17:02:47.234336 5517 init_comm.go:68] [console] hyper_event_read
690I0922 17:02:47.235061 5517 init_comm.go:68] [console] get length 657
691I0922 17:02:47.236295 5517 init_comm.go:68] [console] read 145 bytes data, total data 657
692I0922 17:02:47.237942 5517 init_comm.go:68] [console] hyper send type 14, len 4
693I0922 17:02:47.238526 5517 init_comm.go:106] read 8/8 [length = 0]
694I0922 17:02:47.238773 5517 init_comm.go:110] data length is 12
695I0922 17:02:47.239047 5517 init_comm.go:96] trying to read 4 bytes
696I0922 17:02:47.239281 5517 init_comm.go:106] read 12/12 [length = 12]
697I0922 17:02:47.239582 5517 init_comm.go:96] trying to read 8 bytes
698I0922 17:02:47.239879 5517 init_comm.go:225] got cmd:14
699I0922 17:02:47.240386 5517 init_comm.go:288] get command NEXT
700I0922 17:02:47.240760 5517 init_comm.go:291] send 157, receive 145
701I0922 17:02:47.275977 5517 init_comm.go:68] [console] 0 0 0 1 0 0 2 91 7b 22 68 6f 73 74 6e 61 6d 65 22 3a 22 62 75 73 79 62 6f 78 2d 37 38 36 36 38 30 30 35 31 38 22 2c 22 63 6f 6e 74 61 69 6e 65 72 73 22 3a 5b 7b 22 69 64 22 3a 22 37 66 37 62 39 32 61 39 33 39 61 34 61 38 31 33 63 38 31 66 32 37 31 31 63 39 38 63 34 38 31 31 66 32 61 64 38 61 64 33 63 61 62 34 31 34 30 39 32 36 62 65 32 34 37 62 37 33 66 61 37 31 31 32 22 2c 22 72 6f 6f 74 66 73 22 3a 22 2f 72 6f 6f 74 66 73 22 2c 22 66 73 74 79 70 65 22 3a 22 78 66 73 22 2c 22 69 6d 61 67 65 22 3a 22 73 64 61 22 2c 22 66 73 6d 61 70 22 3a 5b 7b 22 73 6f 75 72 63 65 22 3a 22 77 6b 4b 68 69 76 7a 43 78 62 22 2c 22 70 61 74 68 22 3a 22 2f 65 74 63 2f 68 6f 73 74 73 22 2c 22 72 65 61 64 4f 6e 6c 79 22 3a 66 61 6c 73 65 2c 22 64 6f 63 6b 65 72 56 6f 6c 75 6d 65 22 3a 66 61 6c 73 65 7d 5d 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 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 74 72 75 65 7d 5d 2c 22 69 6e 74 65 72 66 61 63 65 73 22 3a 5b 7b 22 64 65 76 69 63 65 22 3a 22 65 74 68 30 22 2c 22 69 70 41 64 64 72 65 73 73 22 3a 22 31 39 32 2e 31 36 38 2e 31 32 33 2e 32 22 2c 22 6e 65 74 4d 61 73 6b 22 3a 22 32 35 35 2e 32 35 35 2e 32 35 35 2e 30 22 7d 5d 2c 22 72 6f 75 74 65 73 22 3a 5b 7b 22 64 65 73 74 22 3a 22 30 2e 30 2e 30 2e 30 2f 30 22 2c 22 67 61 74 65 77 61 79 22 3a 22 31 39 32 2e 31 36 38 2e 31 32 33 2e 31 22 2c 22 64 65 76 69 63 65 22 3a 22 65 74 68 30 22 7d 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
702I0922 17:02:47.276827 5517 init_comm.go:68] [console] hyper_channel_handle, type 1, len 657
703I0922 17:02:47.291449 5517 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"busybox-7866800518","containers":[{"id":"7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112","rootfs":"/rootfs","fstype":"xfs","image":"sda","fsmap":[{"source":"wkKhivzCxb","path":"/etc/hosts","readOnly":false,"dockerVolume":false}],"process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"}],"workdir":"/"},"restartPolicy":"never","initialize":true}],"interfaces":[{"device":"eth0","ipAddress":"192.168.123.2","netMask":"255.255.255.0"}],"routes":[{"dest":"0.0.0.0/0","gateway":"192.168.123.1","device":"eth0"}],"shareDir":"share_dir"}, len 649
704I0922 17:02:47.304280 5517 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"busybox-7866800518","containers":[{"id":"7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112","rootfs":"/rootfs","fstype":"xfs","image":"sda","fsmap":[{"source":"wkKhivzCxb","path":"/etc/hosts","readOnly":false,"dockerVolume":false}],"process":{"terminal":true,"stdio":1,"args":["sh"],"envs":[{"env":"PATH","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"}],"workdir":"/"},"restartPolicy":"never","initialize":true}],"interfaces":[{"device":"eth0","ipAddress":"192.168.123.2","netMask":"255.255.255.0"}],"routes":[{"dest":"0.0.0.0/0","gateway":"192.168.123.1","device":"eth0"}],"shareDir":"share_dir"}, len 649
705I0922 17:02:47.307208 5517 init_comm.go:68] [console] random: busybox urandom read with 20 bits of entropy available
706I0922 17:02:47.308967 5517 init_comm.go:68] [console] jsmn parse successed, n is 67
707I0922 17:02:47.309977 5517 init_comm.go:68] [console] token 0, type is 1, size is 5
708I0922 17:02:47.312178 5517 init_comm.go:68] [console] token 1, type is 3, size is 1
709I0922 17:02:47.313252 5517 init_comm.go:68] [console] hostname is busybox-7866800518
710I0922 17:02:47.314239 5517 init_comm.go:68] [console] token 3, type is 3, size is 1
711I0922 17:02:47.314989 5517 init_comm.go:68] [console] container count 1
712I0922 17:02:47.315673 5517 init_comm.go:68] [console] next container 8
713I0922 17:02:47.316154 5517 init_comm.go:68] [console] 1 name id
714I0922 17:02:47.318337 5517 init_comm.go:68] [console] container id 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
715I0922 17:02:47.319753 5517 init_comm.go:68] [console] 3 name rootfs
716I0922 17:02:47.320445 5517 init_comm.go:68] [console] container rootfs /rootfs
717I0922 17:02:47.320953 5517 init_comm.go:68] [console] 5 name fstype
718I0922 17:02:47.321687 5517 init_comm.go:68] [console] container fstype xfs
719I0922 17:02:47.322175 5517 init_comm.go:68] [console] 7 name image
720I0922 17:02:47.322865 5517 init_comm.go:68] [console] container image sda
721I0922 17:02:47.323365 5517 init_comm.go:68] [console] 9 name fsmap
722I0922 17:02:47.323895 5517 init_comm.go:68] [console] fsmap num 1
723I0922 17:02:47.325035 5517 init_comm.go:68] [console] maps 0 source wkKhivzCxb
724I0922 17:02:47.326261 5517 init_comm.go:68] [console] maps 0 path /etc/hosts
725I0922 17:02:47.327328 5517 init_comm.go:68] [console] maps 0 readonly 0
726I0922 17:02:47.328574 5517 init_comm.go:68] [console] maps 0 docker volume 0
727I0922 17:02:47.329668 5517 init_comm.go:68] [console] 20 name process
728I0922 17:02:47.330661 5517 init_comm.go:68] [console] 1 name terminal
729I0922 17:02:47.331967 5517 init_comm.go:68] [console] container uses terminal
730I0922 17:02:47.332880 5517 init_comm.go:68] [console] 3 name stdio
731I0922 17:02:47.333970 5517 init_comm.go:68] [console] container seq 1
732I0922 17:02:47.335101 5517 init_comm.go:68] [console] 5 name args
733I0922 17:02:47.336809 5517 init_comm.go:68] [console] container init arg 0 sh
734I0922 17:02:47.338280 5517 init_comm.go:68] [console] 8 name envs
735I0922 17:02:47.339667 5517 init_comm.go:68] [console] envs num 1
736I0922 17:02:47.341144 5517 init_comm.go:68] [console] envs 0 env PATH
737I0922 17:02:47.343376 5517 init_comm.go:68] [console] envs 0 value /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
738I0922 17:02:47.344426 5517 init_comm.go:68] [console] 15 name workdir
739I0922 17:02:47.346373 5517 init_comm.go:68] [console] container workdir /
740I0922 17:02:47.347299 5517 init_comm.go:68] [console] 38 name restartPolicy
741I0922 17:02:47.348026 5517 init_comm.go:68] [console] restart policy never
742I0922 17:02:47.348762 5517 init_comm.go:68] [console] 40 name initialize
743I0922 17:02:47.349669 5517 init_comm.go:68] [console] need to initialize container
744I0922 17:02:47.350580 5517 init_comm.go:68] [console] token 47, type is 3, size is 1
745I0922 17:02:47.351299 5517 init_comm.go:68] [console] network interfaces num 1
746I0922 17:02:47.352829 5517 init_comm.go:68] [console] net device is eth0
747I0922 17:02:47.354945 5517 init_comm.go:68] [console] net ipaddress is 192.168.123.2
748I0922 17:02:47.356392 5517 init_comm.go:68] [console] net mask is 255.255.255.0
749I0922 17:02:47.358016 5517 init_comm.go:68] [console] token 56, type is 3, size is 1
750I0922 17:02:47.359230 5517 init_comm.go:68] [console] network routes num 1
751I0922 17:02:47.360551 5517 init_comm.go:68] [console] route 0 dest is 0.0.0.0/0
752I0922 17:02:47.362027 5517 init_comm.go:68] [console] route 0 gateway is 192.168.123.1
753I0922 17:02:47.362662 5517 init_comm.go:68] [console] route 0 device is eth0
754I0922 17:02:47.363362 5517 init_comm.go:68] [console] token 65, type is 3, size is 1
755I0922 17:02:47.364026 5517 init_comm.go:68] [console] share tag is share_dir
756I0922 17:02:47.364740 5517 init_comm.go:68] [console] create directory /tmp
757I0922 17:02:47.365399 5517 init_comm.go:68] [console] create directory /tmp/hyper
758I0922 17:02:47.366166 5517 init_comm.go:68] [console] create directory /tmp/hyper/proc
759I0922 17:02:47.367288 5517 init_comm.go:68] [console] finish rescan
760I0922 17:02:47.368220 5517 init_comm.go:68] [console] net device eth0
761I0922 17:02:47.370992 5517 init_comm.go:68] [console] net device sys path is /sys/class/net/eth0/ifindex
762I0922 17:02:47.371562 5517 init_comm.go:68] [console] get ifindex 2
763I0922 17:02:47.372653 5517 init_comm.go:68] [console] interface get netamsk 24 255.255.255.0
764I0922 17:02:47.373043 5517 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1474534967, "microseconds": 372932}, "event": "NIC_RX_FILTER_CHANGED", "data": {"name": "eth0", "path": "/machine/peripheral/eth0/virtio-backend"}}
765I0922 17:02:47.373257 5517 qmp_handler.go:107] got event: NIC_RX_FILTER_CHANGED
766I0922 17:02:47.373577 5517 qmp_handler.go:323] got QMP event NIC_RX_FILTER_CHANGED
767I0922 17:02:47.373842 5517 init_comm.go:68] [console] net device eth0
768I0922 17:02:47.375342 5517 init_comm.go:68] [console] net device sys path is /sys/class/net/eth0/ifindex
769I0922 17:02:47.375885 5517 init_comm.go:68] [console] get ifindex 2
770I0922 17:02:47.377535 5517 init_comm.go:68] [console] create directory /tmp/hyper/shared
771I0922 17:02:47.380209 5517 init_comm.go:68] [console] pod init pid 328
772I0922 17:02:47.380994 5517 init_comm.go:68] [console] hyper send type 8, len 0
773I0922 17:02:47.382900 5517 init_comm.go:68] [console] create directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
774I0922 17:02:47.385642 5517 init_comm.go:68] [console] create directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/devpts
775I0922 17:02:47.387677 5517 init_comm.go:68] [console] create directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/devpts/
776I0922 17:02:47.388391 5517 init_comm.go:68] [console] hyper send type 8, len 0
777I0922 17:02:47.389998 5517 init_comm.go:68] [console] create child process pid=330 in the sandbox
778I0922 17:02:47.391144 5517 init_comm.go:68] [console] path /sys/class/scsi_host/host0/scan
779I0922 17:02:47.417532 5517 init_comm.go:68] [console] finish scan scsi
780I0922 17:02:47.422066 5517 init_comm.go:68] [console] create directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/root
781I0922 17:02:47.424315 5517 init_comm.go:68] [console] create directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/root/
782I0922 17:02:47.427469 5517 init_comm.go:68] [console] container root directory /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/root/
783I0922 17:02:47.428342 5517 init_comm.go:68] [console] device /dev/sda
784I0922 17:02:47.431010 5517 init_comm.go:68] [console] XFS (sda): Mounting V5 Filesystem
785I0922 17:02:47.456689 5517 init_comm.go:68] [console] XFS (sda): Ending clean mount
786I0922 17:02:47.459642 5517 init_comm.go:68] [console] root directory for container is /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/root///rootfs, init task sh
787I0922 17:02:47.460793 5517 init_comm.go:68] [console] recreate file ./etc/hosts
788I0922 17:02:47.461585 5517 init_comm.go:68] [console] recreate file ./etc/hostname
789I0922 17:02:47.462580 5517 init_comm.go:68] [console] recreate symlink ./etc/mtab to /proc/mounts
790I0922 17:02:47.465067 5517 init_comm.go:68] [console] create directory ./lib
791I0922 17:02:47.466322 5517 init_comm.go:68] [console] create directory ./lib/modules
792I0922 17:02:47.467958 5517 init_comm.go:68] [console] create directory ./dev/shm
793I0922 17:02:47.469081 5517 init_comm.go:68] [console] create directory .//lib/modules/4.4.12-hyper
794I0922 17:02:47.471529 5517 init_comm.go:68] [console] mount /tmp/hyper/shared/wkKhivzCxb to .//etc/hosts
795I0922 17:02:47.472679 5517 init_comm.go:68] [console] no dns configured
796I0922 17:02:47.473546 5517 init_comm.go:68] [console] hyper send type 8, len 0
797I0922 17:02:47.475528 5517 init_comm.go:68] [console] get pty device for exec /tmp/hyper/7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112/devpts//0
798I0922 17:02:47.476760 5517 init_comm.go:68] [console] hyper_setup_exec_tty pts event 0x223e830, fd 6 7
799I0922 17:02:47.479138 5517 init_comm.go:68] [console] hyper_init_event container pts event 0x223e830, ops 0x61c540, fd 6
800I0922 17:02:47.480316 5517 init_comm.go:68] [console] hyper_add_event add event fd 6, 0x61c540
801I0922 17:02:47.481437 5517 init_comm.go:68] [console] hyper_add_event add event fd 8, 0x61c500
802I0922 17:02:47.482523 5517 init_comm.go:68] [console] hyper_add_event add event fd 9, 0x61c4c0
803I0922 17:02:47.483224 5517 init_comm.go:68] [console] do_exec_cmd pid 595
804I0922 17:02:47.484440 5517 init_comm.go:68] [console] create child process pid=596 in the sandbox
805I0922 17:02:47.486002 5517 init_comm.go:68] [console] hyper send type 596, len 0
806I0922 17:02:47.486914 5517 init_comm.go:68] [console] hyper_run_process get ready message 596
807I0922 17:02:47.487492 5517 init_comm.go:68] [console] uptime 0.88 0.10
808I0922 17:02:47.487848 5517 init_comm.go:68] [console]
809I0922 17:02:47.488630 5517 init_comm.go:68] [console] hyper send type 9, len 0
810I0922 17:02:47.488938 5517 init_comm.go:106] read 8/8 [length = 0]
811I0922 17:02:47.489094 5517 init_comm.go:110] data length is 8
812I0922 17:02:47.489268 5517 init_comm.go:96] trying to read 8 bytes
813I0922 17:02:47.489484 5517 init_comm.go:225] got cmd:9
814I0922 17:02:47.489786 5517 init_comm.go:244] ack got, clear pong timer
815I0922 17:02:47.489792 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
816I0922 17:02:47.489982 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 31(COMMAND_ACK)
817I0922 17:02:47.490432 5517 vm_states.go:490] [starting] got init ack to &{1 859538460608 <nil> [] 859538835136}
818I0922 17:02:47.490882 5517 context.go:260] VM vm-iGMHsoEeXV: state change from STARTING to 'RUNNING'
819I0922 17:02:47.491100 5517 vm_states.go:506] pod start success
820I0922 17:02:47.491083 5517 vm.go:275] Get the response from VM, VM id is vm-iGMHsoEeXV!
821I0922 17:02:47.491639 5517 pod.go:1299] Add or Update the VM info for pod(pod-OUfBbohkAW)
822I0922 17:02:47.491939 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c600, fd 3. ops 0x61c3e0
823I0922 17:02:47.491928 5517 pod.go:332] unlock pod pod-OUfBbohkAW for operation start
824I0922 17:02:47.492304 5517 pod.go:335] successfully unlock pod pod-OUfBbohkAW for operation start
825I0922 17:02:47.492727 5517 init_comm.go:68] [console] hyper_dup_exec_tty
826I0922 17:02:47.494452 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c600, fd 3, 0x61c3e0
827I0922 17:02:47.495075 5517 init_comm.go:68] [console] hyper_event_read
828I0922 17:02:47.496153 5517 init_comm.go:68] [console] already read 8 bytes data
829I0922 17:02:47.497612 5517 init_comm.go:68] [console] hyper send type 14, len 4
830I0922 17:02:47.498173 5517 init_comm.go:106] read 8/8 [length = 0]
831I0922 17:02:47.498406 5517 init_comm.go:110] data length is 12
832I0922 17:02:47.498718 5517 init_comm.go:96] trying to read 4 bytes
833I0922 17:02:47.499006 5517 init_comm.go:106] read 12/12 [length = 12]
834I0922 17:02:47.499188 5517 init_comm.go:96] trying to read 8 bytes
835I0922 17:02:47.499286 5517 init_comm.go:225] got cmd:14
836I0922 17:02:47.499312 5517 init_comm.go:288] get command NEXT
837I0922 17:02:47.499339 5517 init_comm.go:291] send 157, receive 153
838I0922 17:02:47.499388 5517 init_comm.go:68] [console] get length 12
839I0922 17:02:47.499509 5517 init_comm.go:68] [console] read 4 bytes data, total data 12
840I0922 17:02:47.500758 5517 init_comm.go:68] [console] hyper send type 14, len 4
841I0922 17:02:47.501203 5517 init_comm.go:106] read 8/8 [length = 0]
842I0922 17:02:47.501387 5517 init_comm.go:110] data length is 12
843I0922 17:02:47.501437 5517 init_comm.go:96] trying to read 4 bytes
844I0922 17:02:47.501521 5517 init_comm.go:106] read 12/12 [length = 12]
845I0922 17:02:47.501598 5517 init_comm.go:96] trying to read 8 bytes
846I0922 17:02:47.501732 5517 init_comm.go:225] got cmd:14
847I0922 17:02:47.501805 5517 init_comm.go:288] get command NEXT
848I0922 17:02:47.502030 5517 init_comm.go:291] send 157, receive 157
849I0922 17:02:47.503178 5517 init_comm.go:68] [console] 0 0 0 0 0 0 0 c 6e 75 6c 6c
850I0922 17:02:47.505498 5517 init_comm.go:68] [console] hyper_channel_handle, type 0, len 12
851I0922 17:02:47.507403 5517 init_comm.go:68] [console] hyper send type 9, len 4
852I0922 17:02:47.507995 5517 init_comm.go:106] read 8/8 [length = 0]
853I0922 17:02:47.508119 5517 init_comm.go:110] data length is 12
854I0922 17:02:47.508166 5517 init_comm.go:96] trying to read 4 bytes
855I0922 17:02:47.508244 5517 init_comm.go:106] read 12/12 [length = 12]
856I0922 17:02:47.508339 5517 init_comm.go:96] trying to read 8 bytes
857I0922 17:02:47.508670 5517 init_comm.go:225] got cmd:9
858I0922 17:02:47.508776 5517 init_comm.go:198] hyperstart API version:4242, VM hyperstart API version: 4242
859I0922 17:02:47.509782 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
860I0922 17:02:47.513318 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
861I0922 17:02:47.515143 5517 init_comm.go:68] [console] write_to_stdin, seq 1
862I0922 17:02:47.517465 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
863I0922 17:02:47.519766 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
864I0922 17:02:47.522641 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
865I0922 17:02:47.524065 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
866I0922 17:02:47.524978 5517 init_comm.go:68] [console] stderr_loop, seq 0
867I0922 17:02:47.526053 5517 init_comm.go:68] [console] pts_loop: read 4 data
868I0922 17:02:47.527118 5517 init_comm.go:68] [console] pts_loop: read -1 data
869I0922 17:02:47.528914 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
870I0922 17:02:47.530966 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
871I0922 17:02:47.532905 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
872I0922 17:02:47.533839 5517 init_comm.go:68] [console] stdout_loop, seq 1
873I0922 17:02:47.534793 5517 init_comm.go:68] [console] pts_loop: read -1 data
874I0922 17:02:47.535901 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
875I0922 17:02:47.537881 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
876I0922 17:02:47.539574 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
877I0922 17:02:47.539978 5517 tty.go:108] tty: read 12/12 [length = 0]
878I0922 17:02:47.540001 5517 tty.go:112] data length is 16
879I0922 17:02:47.540007 5517 tty.go:98] tty: trying to read 4 bytes
880I0922 17:02:47.540018 5517 tty.go:108] tty: read 16/16 [length = 16]
881I0922 17:02:47.540045 5517 tty.go:98] tty: trying to read 12 bytes
882I0922 17:02:47.541865 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
883I0922 17:02:47.542927 5517 init_comm.go:68] [console] pid 327 exit normally, status 0
884I0922 17:02:47.544191 5517 init_comm.go:68] [console] exec pid 596, pid 327
885I0922 17:02:47.545829 5517 init_comm.go:68] [console] can not find exec whose pid is 327
886I0922 17:02:47.547186 5517 init_comm.go:68] [console] pid 329 exit normally, status 0
887I0922 17:02:47.548257 5517 init_comm.go:68] [console] exec pid 596, pid 329
888I0922 17:02:47.549833 5517 init_comm.go:68] [console] can not find exec whose pid is 329
889I0922 17:02:47.551860 5517 init_comm.go:68] [console] pid 330 exit normally, status 0
890I0922 17:02:47.553151 5517 init_comm.go:68] [console] exec pid 596, pid 330
891I0922 17:02:47.554587 5517 init_comm.go:68] [console] can not find exec whose pid is 330
892I0922 17:02:47.555941 5517 init_comm.go:68] [console] pid 595 exit normally, status 0
893I0922 17:02:47.557026 5517 init_comm.go:68] [console] exec pid 596, pid 595
894I0922 17:02:47.558448 5517 init_comm.go:68] [console] can not find exec whose pid is 595
895I0922 17:02:47.559586 5517 init_comm.go:68] [console] hyper_loop epoll_wait -1
896I0922 17:03:05.770293 5517 tty.go:426] trying to input char: 115 and 1 chars
897I0922 17:03:05.770402 5517 tty.go:133] trying to write to session 1
898I0922 17:03:05.772712 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
899I0922 17:03:05.776086 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
900I0922 17:03:05.779636 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
901I0922 17:03:05.780680 5517 init_comm.go:68] [console] hyper_event_read
902I0922 17:03:05.781908 5517 init_comm.go:68] [console] already read 12 bytes data
903I0922 17:03:05.782743 5517 init_comm.go:68] [console] get length 13
904I0922 17:03:05.783979 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
905I0922 17:03:05.784786 5517 init_comm.go:68] [console] exec seq 1, seq 1
906I0922 17:03:05.786897 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
907I0922 17:03:05.788057 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
908I0922 17:03:05.789721 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
909I0922 17:03:05.791757 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
910I0922 17:03:05.792607 5517 init_comm.go:68] [console] write_to_stdin, seq 1
911I0922 17:03:05.794590 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
912I0922 17:03:05.795492 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
913I0922 17:03:05.797069 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
914I0922 17:03:05.799689 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
915I0922 17:03:05.800530 5517 init_comm.go:68] [console] stderr_loop, seq 0
916I0922 17:03:05.801598 5517 init_comm.go:68] [console] pts_loop: read 1 data
917I0922 17:03:05.802514 5517 init_comm.go:68] [console] pts_loop: read -1 data
918I0922 17:03:05.804720 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
919I0922 17:03:05.806494 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
920I0922 17:03:05.808577 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
921I0922 17:03:05.809558 5517 init_comm.go:68] [console] stdout_loop, seq 1
922I0922 17:03:05.810568 5517 init_comm.go:68] [console] pts_loop: read -1 data
923I0922 17:03:05.811461 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
924I0922 17:03:05.813484 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
925I0922 17:03:05.815146 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
926I0922 17:03:05.815472 5517 tty.go:108] tty: read 12/12 [length = 0]
927I0922 17:03:05.815484 5517 tty.go:112] data length is 13
928I0922 17:03:05.815487 5517 tty.go:98] tty: trying to read 1 bytes
929I0922 17:03:05.815492 5517 tty.go:108] tty: read 13/13 [length = 13]
930I0922 17:03:05.815513 5517 tty.go:98] tty: trying to read 12 bytes
931I0922 17:03:05.817144 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
932I0922 17:03:05.949939 5517 tty.go:426] trying to input char: 32 and 1 chars
933I0922 17:03:05.950050 5517 tty.go:133] trying to write to session 1
934I0922 17:03:05.959046 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
935I0922 17:03:05.959080 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
936I0922 17:03:05.959086 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
937I0922 17:03:05.959089 5517 init_comm.go:68] [console] hyper_event_read
938I0922 17:03:05.959092 5517 init_comm.go:68] [console] already read 12 bytes data
939I0922 17:03:05.959095 5517 init_comm.go:68] [console] get length 13
940I0922 17:03:05.959098 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
941I0922 17:03:05.959114 5517 init_comm.go:68] [console] exec seq 1, seq 1
942I0922 17:03:05.961168 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
943I0922 17:03:05.962255 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
944I0922 17:03:05.964442 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
945I0922 17:03:05.966551 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
946I0922 17:03:05.967540 5517 init_comm.go:68] [console] write_to_stdin, seq 1
947I0922 17:03:05.969536 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
948I0922 17:03:05.970809 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
949I0922 17:03:05.973232 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
950I0922 17:03:05.975430 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
951I0922 17:03:05.976654 5517 init_comm.go:68] [console] stderr_loop, seq 0
952I0922 17:03:05.978333 5517 init_comm.go:68] [console] pts_loop: read 1 data
953I0922 17:03:05.979491 5517 init_comm.go:68] [console] pts_loop: read -1 data
954I0922 17:03:05.981538 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
955I0922 17:03:05.983891 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
956I0922 17:03:05.986301 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
957I0922 17:03:05.987227 5517 init_comm.go:68] [console] stdout_loop, seq 1
958I0922 17:03:05.988421 5517 init_comm.go:68] [console] pts_loop: read -1 data
959I0922 17:03:05.989535 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
960I0922 17:03:05.991636 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
961I0922 17:03:05.994268 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
962I0922 17:03:05.994599 5517 tty.go:108] tty: read 12/12 [length = 0]
963I0922 17:03:05.994626 5517 tty.go:112] data length is 13
964I0922 17:03:05.994631 5517 tty.go:98] tty: trying to read 1 bytes
965I0922 17:03:05.994636 5517 tty.go:108] tty: read 13/13 [length = 13]
966I0922 17:03:05.994692 5517 tty.go:98] tty: trying to read 12 bytes
967I0922 17:03:05.996641 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
968I0922 17:03:06.264842 5517 tty.go:426] trying to input char: 127 and 1 chars
969I0922 17:03:06.264962 5517 tty.go:133] trying to write to session 1
970I0922 17:03:06.267247 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
971I0922 17:03:06.270549 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
972I0922 17:03:06.273791 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
973I0922 17:03:06.274914 5517 init_comm.go:68] [console] hyper_event_read
974I0922 17:03:06.276343 5517 init_comm.go:68] [console] already read 12 bytes data
975I0922 17:03:06.277284 5517 init_comm.go:68] [console] get length 13
976I0922 17:03:06.278683 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
977I0922 17:03:06.279720 5517 init_comm.go:68] [console] exec seq 1, seq 1
978I0922 17:03:06.281905 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
979I0922 17:03:06.283080 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
980I0922 17:03:06.285406 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
981I0922 17:03:06.287775 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
982I0922 17:03:06.289014 5517 init_comm.go:68] [console] write_to_stdin, seq 1
983I0922 17:03:06.291116 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
984I0922 17:03:06.292448 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
985I0922 17:03:06.294925 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
986I0922 17:03:06.297204 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
987I0922 17:03:06.298248 5517 init_comm.go:68] [console] stderr_loop, seq 0
988I0922 17:03:06.299342 5517 init_comm.go:68] [console] pts_loop: read 4 data
989I0922 17:03:06.300504 5517 init_comm.go:68] [console] pts_loop: read -1 data
990I0922 17:03:06.302574 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
991I0922 17:03:06.305367 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
992I0922 17:03:06.307627 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
993I0922 17:03:06.308643 5517 init_comm.go:68] [console] stdout_loop, seq 1
994I0922 17:03:06.310554 5517 init_comm.go:68] [console] pts_loop: read -1 data
995I0922 17:03:06.312440 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
996I0922 17:03:06.316118 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
997I0922 17:03:06.318617 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
998I0922 17:03:06.319008 5517 tty.go:108] tty: read 12/12 [length = 0]
999I0922 17:03:06.319054 5517 tty.go:112] data length is 16
1000I0922 17:03:06.319062 5517 tty.go:98] tty: trying to read 4 bytes
1001I0922 17:03:06.319070 5517 tty.go:108] tty: read 16/16 [length = 16]
1002I0922 17:03:06.319103 5517 tty.go:98] tty: trying to read 12 bytes
1003I0922 17:03:06.321691 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1004I0922 17:03:06.399836 5517 tty.go:426] trying to input char: 127 and 1 chars
1005I0922 17:03:06.399950 5517 tty.go:133] trying to write to session 1
1006I0922 17:03:06.402194 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1007I0922 17:03:06.406564 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1008I0922 17:03:06.409405 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1009I0922 17:03:06.410378 5517 init_comm.go:68] [console] hyper_event_read
1010I0922 17:03:06.411589 5517 init_comm.go:68] [console] already read 12 bytes data
1011I0922 17:03:06.412414 5517 init_comm.go:68] [console] get length 13
1012I0922 17:03:06.413677 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1013I0922 17:03:06.414747 5517 init_comm.go:68] [console] exec seq 1, seq 1
1014I0922 17:03:06.416649 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1015I0922 17:03:06.417742 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1016I0922 17:03:06.419945 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1017I0922 17:03:06.422215 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1018I0922 17:03:06.423236 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1019I0922 17:03:06.425184 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1020I0922 17:03:06.427046 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1021I0922 17:03:06.429597 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1022I0922 17:03:06.432195 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1023I0922 17:03:06.433866 5517 init_comm.go:68] [console] stderr_loop, seq 0
1024I0922 17:03:06.435065 5517 init_comm.go:68] [console] pts_loop: read 4 data
1025I0922 17:03:06.436123 5517 init_comm.go:68] [console] pts_loop: read -1 data
1026I0922 17:03:06.438452 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1027I0922 17:03:06.440730 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1028I0922 17:03:06.442816 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1029I0922 17:03:06.443745 5517 init_comm.go:68] [console] stdout_loop, seq 1
1030I0922 17:03:06.444781 5517 init_comm.go:68] [console] pts_loop: read -1 data
1031I0922 17:03:06.445823 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1032I0922 17:03:06.447941 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1033I0922 17:03:06.450124 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1034I0922 17:03:06.450441 5517 tty.go:108] tty: read 12/12 [length = 0]
1035I0922 17:03:06.450471 5517 tty.go:112] data length is 16
1036I0922 17:03:06.450478 5517 tty.go:98] tty: trying to read 4 bytes
1037I0922 17:03:06.450484 5517 tty.go:108] tty: read 16/16 [length = 16]
1038I0922 17:03:06.450515 5517 tty.go:98] tty: trying to read 12 bytes
1039I0922 17:03:06.452468 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1040I0922 17:03:06.501221 5517 tty.go:426] trying to input char: 127 and 1 chars
1041I0922 17:03:06.501309 5517 tty.go:133] trying to write to session 1
1042I0922 17:03:06.502945 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1043I0922 17:03:06.505998 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1044I0922 17:03:06.508593 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1045I0922 17:03:06.509560 5517 init_comm.go:68] [console] hyper_event_read
1046I0922 17:03:06.510768 5517 init_comm.go:68] [console] already read 12 bytes data
1047I0922 17:03:06.511557 5517 init_comm.go:68] [console] get length 13
1048I0922 17:03:06.512836 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1049I0922 17:03:06.513753 5517 init_comm.go:68] [console] exec seq 1, seq 1
1050I0922 17:03:06.515658 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1051I0922 17:03:06.516752 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1052I0922 17:03:06.518859 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1053I0922 17:03:06.521067 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1054I0922 17:03:06.522328 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1055I0922 17:03:06.524406 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1056I0922 17:03:06.827038 5517 tty.go:426] trying to input char: 108 and 1 chars
1057I0922 17:03:06.827135 5517 tty.go:133] trying to write to session 1
1058I0922 17:03:06.828740 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1059I0922 17:03:06.831481 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1060I0922 17:03:06.833852 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1061I0922 17:03:06.834701 5517 init_comm.go:68] [console] hyper_event_read
1062I0922 17:03:06.835823 5517 init_comm.go:68] [console] already read 12 bytes data
1063I0922 17:03:06.836550 5517 init_comm.go:68] [console] get length 13
1064I0922 17:03:06.837837 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1065I0922 17:03:06.838717 5517 init_comm.go:68] [console] exec seq 1, seq 1
1066I0922 17:03:06.840631 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1067I0922 17:03:06.841720 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1068I0922 17:03:06.844583 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1069I0922 17:03:06.846880 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1070I0922 17:03:06.848071 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1071I0922 17:03:06.850282 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1072I0922 17:03:06.851554 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1073I0922 17:03:06.854175 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1074I0922 17:03:06.857798 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1075I0922 17:03:06.858972 5517 init_comm.go:68] [console] stderr_loop, seq 0
1076I0922 17:03:06.860117 5517 init_comm.go:68] [console] pts_loop: read 1 data
1077I0922 17:03:06.861816 5517 init_comm.go:68] [console] pts_loop: read -1 data
1078I0922 17:03:06.863938 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1079I0922 17:03:06.866119 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1080I0922 17:03:06.868387 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1081I0922 17:03:06.869311 5517 init_comm.go:68] [console] stdout_loop, seq 1
1082I0922 17:03:06.870344 5517 init_comm.go:68] [console] pts_loop: read -1 data
1083I0922 17:03:06.871507 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1084I0922 17:03:06.873643 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1085I0922 17:03:06.876407 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1086I0922 17:03:06.876804 5517 tty.go:108] tty: read 12/12 [length = 0]
1087I0922 17:03:06.876837 5517 tty.go:112] data length is 13
1088I0922 17:03:06.876845 5517 tty.go:98] tty: trying to read 1 bytes
1089I0922 17:03:06.876854 5517 tty.go:108] tty: read 13/13 [length = 13]
1090I0922 17:03:06.876902 5517 tty.go:98] tty: trying to read 12 bytes
1091I0922 17:03:06.878989 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1092I0922 17:03:06.906620 5517 tty.go:426] trying to input char: 115 and 1 chars
1093I0922 17:03:06.906682 5517 tty.go:133] trying to write to session 1
1094I0922 17:03:06.908308 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1095I0922 17:03:06.911257 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1096I0922 17:03:06.913900 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1097I0922 17:03:06.914816 5517 init_comm.go:68] [console] hyper_event_read
1098I0922 17:03:06.916031 5517 init_comm.go:68] [console] already read 12 bytes data
1099I0922 17:03:06.916805 5517 init_comm.go:68] [console] get length 13
1100I0922 17:03:06.918155 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1101I0922 17:03:06.919043 5517 init_comm.go:68] [console] exec seq 1, seq 1
1102I0922 17:03:06.921300 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1103I0922 17:03:06.922436 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1104I0922 17:03:06.924651 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1105I0922 17:03:06.926915 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1106I0922 17:03:06.928014 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1107I0922 17:03:06.930101 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1108I0922 17:03:06.931207 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1109I0922 17:03:06.933309 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1110I0922 17:03:06.935419 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1111I0922 17:03:06.936298 5517 init_comm.go:68] [console] stderr_loop, seq 0
1112I0922 17:03:06.937332 5517 init_comm.go:68] [console] pts_loop: read 1 data
1113I0922 17:03:06.938438 5517 init_comm.go:68] [console] pts_loop: read -1 data
1114I0922 17:03:06.940383 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1115I0922 17:03:06.942528 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1116I0922 17:03:06.944642 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1117I0922 17:03:06.945575 5517 init_comm.go:68] [console] stdout_loop, seq 1
1118I0922 17:03:06.946579 5517 init_comm.go:68] [console] pts_loop: read -1 data
1119I0922 17:03:06.947646 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1120I0922 17:03:06.949722 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1121I0922 17:03:06.951795 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1122I0922 17:03:06.952062 5517 tty.go:108] tty: read 12/12 [length = 0]
1123I0922 17:03:06.952088 5517 tty.go:112] data length is 13
1124I0922 17:03:06.952093 5517 tty.go:98] tty: trying to read 1 bytes
1125I0922 17:03:06.952098 5517 tty.go:108] tty: read 13/13 [length = 13]
1126I0922 17:03:06.952123 5517 tty.go:98] tty: trying to read 12 bytes
1127I0922 17:03:06.953954 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1128I0922 17:03:06.985133 5517 tty.go:426] trying to input char: 32 and 1 chars
1129I0922 17:03:06.985252 5517 tty.go:133] trying to write to session 1
1130I0922 17:03:06.987744 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1131I0922 17:03:06.992407 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1132I0922 17:03:06.995428 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1133I0922 17:03:06.996687 5517 init_comm.go:68] [console] hyper_event_read
1134I0922 17:03:06.998083 5517 init_comm.go:68] [console] already read 12 bytes data
1135I0922 17:03:06.998997 5517 init_comm.go:68] [console] get length 13
1136I0922 17:03:07.000416 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1137I0922 17:03:07.001595 5517 init_comm.go:68] [console] exec seq 1, seq 1
1138I0922 17:03:07.004410 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1139I0922 17:03:07.005535 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1140I0922 17:03:07.007727 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1141I0922 17:03:07.009865 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1142I0922 17:03:07.010862 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1143I0922 17:03:07.012864 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1144I0922 17:03:07.013950 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1145I0922 17:03:07.016103 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1146I0922 17:03:07.018506 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1147I0922 17:03:07.019648 5517 init_comm.go:68] [console] stderr_loop, seq 0
1148I0922 17:03:07.020869 5517 init_comm.go:68] [console] pts_loop: read 1 data
1149I0922 17:03:07.022792 5517 init_comm.go:68] [console] pts_loop: read -1 data
1150I0922 17:03:07.024846 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1151I0922 17:03:07.027678 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1152I0922 17:03:07.029759 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1153I0922 17:03:07.030641 5517 init_comm.go:68] [console] stdout_loop, seq 1
1154I0922 17:03:07.031652 5517 init_comm.go:68] [console] pts_loop: read -1 data
1155I0922 17:03:07.032641 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1156I0922 17:03:07.034671 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1157I0922 17:03:07.036709 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1158I0922 17:03:07.037031 5517 tty.go:108] tty: read 12/12 [length = 0]
1159I0922 17:03:07.037058 5517 tty.go:112] data length is 13
1160I0922 17:03:07.037064 5517 tty.go:98] tty: trying to read 1 bytes
1161I0922 17:03:07.037069 5517 tty.go:108] tty: read 13/13 [length = 13]
1162I0922 17:03:07.037102 5517 tty.go:98] tty: trying to read 12 bytes
1163I0922 17:03:07.038947 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1164I0922 17:03:07.086501 5517 tty.go:426] trying to input char: 47 and 1 chars
1165I0922 17:03:07.086583 5517 tty.go:133] trying to write to session 1
1166I0922 17:03:07.088986 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1167I0922 17:03:07.092185 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1168I0922 17:03:07.095033 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1169I0922 17:03:07.096295 5517 init_comm.go:68] [console] hyper_event_read
1170I0922 17:03:07.097854 5517 init_comm.go:68] [console] already read 12 bytes data
1171I0922 17:03:07.098804 5517 init_comm.go:68] [console] get length 13
1172I0922 17:03:07.100253 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1173I0922 17:03:07.101245 5517 init_comm.go:68] [console] exec seq 1, seq 1
1174I0922 17:03:07.104180 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1175I0922 17:03:07.105465 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1176I0922 17:03:07.107891 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1177I0922 17:03:07.110033 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1178I0922 17:03:07.110992 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1179I0922 17:03:07.113024 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1180I0922 17:03:07.114137 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1181I0922 17:03:07.116247 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1182I0922 17:03:07.118373 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1183I0922 17:03:07.119306 5517 init_comm.go:68] [console] stderr_loop, seq 0
1184I0922 17:03:07.120390 5517 init_comm.go:68] [console] pts_loop: read 1 data
1185I0922 17:03:07.121459 5517 init_comm.go:68] [console] pts_loop: read -1 data
1186I0922 17:03:07.123367 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1187I0922 17:03:07.125525 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1188I0922 17:03:07.128627 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1189I0922 17:03:07.130243 5517 init_comm.go:68] [console] stdout_loop, seq 1
1190I0922 17:03:07.132017 5517 init_comm.go:68] [console] pts_loop: read -1 data
1191I0922 17:03:07.133206 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1192I0922 17:03:07.135448 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1193I0922 17:03:07.137878 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1194I0922 17:03:07.138331 5517 tty.go:108] tty: read 12/12 [length = 0]
1195I0922 17:03:07.138379 5517 tty.go:112] data length is 13
1196I0922 17:03:07.138391 5517 tty.go:98] tty: trying to read 1 bytes
1197I0922 17:03:07.138402 5517 tty.go:108] tty: read 13/13 [length = 13]
1198I0922 17:03:07.138436 5517 tty.go:98] tty: trying to read 12 bytes
1199I0922 17:03:07.140634 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1200I0922 17:03:07.153788 5517 tty.go:426] trying to input char: 100 and 1 chars
1201I0922 17:03:07.153907 5517 tty.go:133] trying to write to session 1
1202I0922 17:03:07.156424 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1203I0922 17:03:07.159556 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1204I0922 17:03:07.162391 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1205I0922 17:03:07.163589 5517 init_comm.go:68] [console] hyper_event_read
1206I0922 17:03:07.165038 5517 init_comm.go:68] [console] already read 12 bytes data
1207I0922 17:03:07.165961 5517 init_comm.go:68] [console] get length 13
1208I0922 17:03:07.167533 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1209I0922 17:03:07.168455 5517 init_comm.go:68] [console] exec seq 1, seq 1
1210I0922 17:03:07.170455 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1211I0922 17:03:07.171539 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1212I0922 17:03:07.173645 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1213I0922 17:03:07.175793 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1214I0922 17:03:07.176802 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1215I0922 17:03:07.178817 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1216I0922 17:03:07.179834 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1217I0922 17:03:07.181945 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1218I0922 17:03:07.184047 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1219I0922 17:03:07.184917 5517 init_comm.go:68] [console] stderr_loop, seq 0
1220I0922 17:03:07.185871 5517 init_comm.go:68] [console] pts_loop: read 1 data
1221I0922 17:03:07.187016 5517 init_comm.go:68] [console] pts_loop: read -1 data
1222I0922 17:03:07.188981 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1223I0922 17:03:07.191299 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1224I0922 17:03:07.193674 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1225I0922 17:03:07.194585 5517 init_comm.go:68] [console] stdout_loop, seq 1
1226I0922 17:03:07.195578 5517 init_comm.go:68] [console] pts_loop: read -1 data
1227I0922 17:03:07.196571 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1228I0922 17:03:07.198664 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1229I0922 17:03:07.200694 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1230I0922 17:03:07.200949 5517 tty.go:108] tty: read 12/12 [length = 0]
1231I0922 17:03:07.200976 5517 tty.go:112] data length is 13
1232I0922 17:03:07.200981 5517 tty.go:98] tty: trying to read 1 bytes
1233I0922 17:03:07.200986 5517 tty.go:108] tty: read 13/13 [length = 13]
1234I0922 17:03:07.201016 5517 tty.go:98] tty: trying to read 12 bytes
1235I0922 17:03:07.202919 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1236I0922 17:03:07.299222 5517 tty.go:426] trying to input char: 101 and 1 chars
1237I0922 17:03:07.299304 5517 tty.go:133] trying to write to session 1
1238I0922 17:03:07.300906 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1239I0922 17:03:07.305844 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1240I0922 17:03:07.309891 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1241I0922 17:03:07.311463 5517 init_comm.go:68] [console] hyper_event_read
1242I0922 17:03:07.313390 5517 init_comm.go:68] [console] already read 12 bytes data
1243I0922 17:03:07.314791 5517 init_comm.go:68] [console] get length 13
1244I0922 17:03:07.317011 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1245I0922 17:03:07.317896 5517 init_comm.go:68] [console] exec seq 1, seq 1
1246I0922 17:03:07.319920 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1247I0922 17:03:07.321320 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1248I0922 17:03:07.323595 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1249I0922 17:03:07.325857 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1250I0922 17:03:07.327296 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1251I0922 17:03:07.329325 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1252I0922 17:03:07.330418 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1253I0922 17:03:07.332565 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1254I0922 17:03:07.334639 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1255I0922 17:03:07.335563 5517 init_comm.go:68] [console] stderr_loop, seq 0
1256I0922 17:03:07.336536 5517 init_comm.go:68] [console] pts_loop: read 1 data
1257I0922 17:03:07.337589 5517 init_comm.go:68] [console] pts_loop: read -1 data
1258I0922 17:03:07.339533 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1259I0922 17:03:07.341675 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1260I0922 17:03:07.343712 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1261I0922 17:03:07.344596 5517 init_comm.go:68] [console] stdout_loop, seq 1
1262I0922 17:03:07.345562 5517 init_comm.go:68] [console] pts_loop: read -1 data
1263I0922 17:03:07.346562 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1264I0922 17:03:07.348662 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1265I0922 17:03:07.350747 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1266I0922 17:03:07.351046 5517 tty.go:108] tty: read 12/12 [length = 0]
1267I0922 17:03:07.351072 5517 tty.go:112] data length is 13
1268I0922 17:03:07.351077 5517 tty.go:98] tty: trying to read 1 bytes
1269I0922 17:03:07.351082 5517 tty.go:108] tty: read 13/13 [length = 13]
1270I0922 17:03:07.351122 5517 tty.go:98] tty: trying to read 12 bytes
1271I0922 17:03:07.353042 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1272I0922 17:03:07.446310 5517 tty.go:426] trying to input char: 9 and 1 chars
1273I0922 17:03:07.446457 5517 tty.go:133] trying to write to session 1
1274I0922 17:03:07.448803 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1275I0922 17:03:07.451969 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1276I0922 17:03:07.454968 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1277I0922 17:03:07.455898 5517 init_comm.go:68] [console] hyper_event_read
1278I0922 17:03:07.457238 5517 init_comm.go:68] [console] already read 12 bytes data
1279I0922 17:03:07.457943 5517 init_comm.go:68] [console] get length 13
1280I0922 17:03:07.459439 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1281I0922 17:03:07.460491 5517 init_comm.go:68] [console] exec seq 1, seq 1
1282I0922 17:03:07.462521 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1283I0922 17:03:07.463637 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1284I0922 17:03:07.465952 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1285I0922 17:03:07.468612 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1286I0922 17:03:07.470884 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1287I0922 17:03:07.473023 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1288I0922 17:03:07.474549 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1289I0922 17:03:07.477444 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1290I0922 17:03:07.479881 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1291I0922 17:03:07.480901 5517 init_comm.go:68] [console] stderr_loop, seq 0
1292I0922 17:03:07.482004 5517 init_comm.go:68] [console] pts_loop: read 16 data
1293I0922 17:03:07.483148 5517 init_comm.go:68] [console] pts_loop: read -1 data
1294I0922 17:03:07.485114 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1295I0922 17:03:07.487517 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1296I0922 17:03:07.489819 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1297I0922 17:03:07.490820 5517 init_comm.go:68] [console] stdout_loop, seq 1
1298I0922 17:03:07.491911 5517 init_comm.go:68] [console] pts_loop: read -1 data
1299I0922 17:03:07.493204 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1300I0922 17:03:07.495675 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1301I0922 17:03:07.497797 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1302I0922 17:03:07.498125 5517 tty.go:108] tty: read 12/12 [length = 0]
1303I0922 17:03:07.498161 5517 tty.go:112] data length is 28
1304I0922 17:03:07.498165 5517 tty.go:98] tty: trying to read 16 bytes
1305I0922 17:03:07.498171 5517 tty.go:108] tty: read 28/28 [length = 28]
1306I0922 17:03:07.498202 5517 tty.go:98] tty: trying to read 12 bytes
1307I0922 17:03:07.500076 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1308I0922 17:03:08.391276 5517 tty.go:426] trying to input char: 107 and 1 chars
1309I0922 17:03:08.391427 5517 tty.go:133] trying to write to session 1
1310I0922 17:03:08.393519 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1311I0922 17:03:08.396879 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1312I0922 17:03:08.399575 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1313I0922 17:03:08.400498 5517 init_comm.go:68] [console] hyper_event_read
1314I0922 17:03:08.401795 5517 init_comm.go:68] [console] already read 12 bytes data
1315I0922 17:03:08.402531 5517 init_comm.go:68] [console] get length 13
1316I0922 17:03:08.403813 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1317I0922 17:03:08.404889 5517 init_comm.go:68] [console] exec seq 1, seq 1
1318I0922 17:03:08.406940 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1319I0922 17:03:08.408014 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1320I0922 17:03:08.410270 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1321I0922 17:03:08.412413 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1322I0922 17:03:08.413371 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1323I0922 17:03:08.415319 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1324I0922 17:03:08.416378 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1325I0922 17:03:08.418487 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1326I0922 17:03:08.420576 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1327I0922 17:03:08.421580 5517 init_comm.go:68] [console] stderr_loop, seq 0
1328I0922 17:03:08.422551 5517 init_comm.go:68] [console] pts_loop: read 1 data
1329I0922 17:03:08.423559 5517 init_comm.go:68] [console] pts_loop: read -1 data
1330I0922 17:03:08.425582 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1331I0922 17:03:08.428154 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1332I0922 17:03:08.430255 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1333I0922 17:03:08.431182 5517 init_comm.go:68] [console] stdout_loop, seq 1
1334I0922 17:03:08.432160 5517 init_comm.go:68] [console] pts_loop: read -1 data
1335I0922 17:03:08.433181 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1336I0922 17:03:08.435249 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1337I0922 17:03:08.437311 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1338I0922 17:03:08.437680 5517 tty.go:108] tty: read 12/12 [length = 0]
1339I0922 17:03:08.437715 5517 tty.go:112] data length is 13
1340I0922 17:03:08.437722 5517 tty.go:98] tty: trying to read 1 bytes
1341I0922 17:03:08.437728 5517 tty.go:108] tty: read 13/13 [length = 13]
1342I0922 17:03:08.437769 5517 tty.go:98] tty: trying to read 12 bytes
1343I0922 17:03:08.439682 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1344I0922 17:03:08.885199 5517 tty.go:426] trying to input char: 118 and 2 chars
1345I0922 17:03:08.885266 5517 tty.go:133] trying to write to session 1
1346I0922 17:03:08.885566 5517 tty.go:426] trying to input char: 13 and 1 chars
1347I0922 17:03:08.885591 5517 tty.go:133] trying to write to session 1
1348I0922 17:03:08.886919 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1349I0922 17:03:08.889308 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1350I0922 17:03:08.891372 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1351I0922 17:03:08.892249 5517 init_comm.go:68] [console] hyper_event_read
1352I0922 17:03:08.893750 5517 init_comm.go:68] [console] already read 12 bytes data
1353I0922 17:03:08.894631 5517 init_comm.go:68] [console] get length 14
1354I0922 17:03:08.896060 5517 init_comm.go:68] [console] read 2 bytes data, total data 14
1355I0922 17:03:08.897087 5517 init_comm.go:68] [console] exec seq 1, seq 1
1356I0922 17:03:08.899142 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1357I0922 17:03:08.900380 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1358I0922 17:03:08.902629 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1359I0922 17:03:08.905332 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1360I0922 17:03:08.906266 5517 init_comm.go:68] [console] hyper_event_read
1361I0922 17:03:08.907609 5517 init_comm.go:68] [console] already read 12 bytes data
1362I0922 17:03:08.908501 5517 init_comm.go:68] [console] get length 13
1363I0922 17:03:08.909869 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1364I0922 17:03:08.910899 5517 init_comm.go:68] [console] exec seq 1, seq 1
1365I0922 17:03:08.913269 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1366I0922 17:03:08.915641 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1367I0922 17:03:08.916738 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1368I0922 17:03:08.919168 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1369I0922 17:03:08.920515 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1370I0922 17:03:08.924453 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1371I0922 17:03:08.929472 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1372I0922 17:03:08.930782 5517 init_comm.go:68] [console] stderr_loop, seq 0
1373I0922 17:03:08.932573 5517 init_comm.go:68] [console] pts_loop: read 49 data
1374I0922 17:03:08.934099 5517 init_comm.go:68] [console] pts_loop: read -1 data
1375I0922 17:03:08.936510 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1376I0922 17:03:08.939288 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1377I0922 17:03:08.941488 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1378I0922 17:03:08.943057 5517 init_comm.go:68] [console] stdout_loop, seq 1
1379I0922 17:03:08.944251 5517 init_comm.go:68] [console] pts_loop: read -1 data
1380I0922 17:03:08.945431 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1381I0922 17:03:08.947700 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1382I0922 17:03:08.949905 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1383I0922 17:03:08.950395 5517 tty.go:108] tty: read 12/12 [length = 0]
1384I0922 17:03:08.950412 5517 tty.go:112] data length is 61
1385I0922 17:03:08.950415 5517 tty.go:98] tty: trying to read 49 bytes
1386I0922 17:03:08.950421 5517 tty.go:108] tty: read 61/61 [length = 61]
1387I0922 17:03:08.950510 5517 tty.go:98] tty: trying to read 12 bytes
1388I0922 17:03:08.952605 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1389I0922 17:03:12.092705 5517 tty.go:426] trying to input char: 100 and 1 chars
1390I0922 17:03:12.092794 5517 tty.go:133] trying to write to session 1
1391I0922 17:03:12.094745 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1392I0922 17:03:12.097821 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1393I0922 17:03:12.100586 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1394I0922 17:03:12.101505 5517 init_comm.go:68] [console] hyper_event_read
1395I0922 17:03:12.102828 5517 init_comm.go:68] [console] already read 12 bytes data
1396I0922 17:03:12.103581 5517 init_comm.go:68] [console] get length 13
1397I0922 17:03:12.104921 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1398I0922 17:03:12.105898 5517 init_comm.go:68] [console] exec seq 1, seq 1
1399I0922 17:03:12.107873 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1400I0922 17:03:12.108938 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1401I0922 17:03:12.111186 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1402I0922 17:03:12.113418 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1403I0922 17:03:12.114479 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1404I0922 17:03:12.116515 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1405I0922 17:03:12.117579 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1406I0922 17:03:12.119788 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1407I0922 17:03:12.122785 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1408I0922 17:03:12.123894 5517 init_comm.go:68] [console] stderr_loop, seq 0
1409I0922 17:03:12.125003 5517 init_comm.go:68] [console] pts_loop: read 1 data
1410I0922 17:03:12.126098 5517 init_comm.go:68] [console] pts_loop: read -1 data
1411I0922 17:03:12.128230 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1412I0922 17:03:12.130408 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1413I0922 17:03:12.132489 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1414I0922 17:03:12.133383 5517 init_comm.go:68] [console] stdout_loop, seq 1
1415I0922 17:03:12.134393 5517 init_comm.go:68] [console] pts_loop: read -1 data
1416I0922 17:03:12.135474 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1417I0922 17:03:12.137565 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1418I0922 17:03:12.139767 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1419I0922 17:03:12.140101 5517 tty.go:108] tty: read 12/12 [length = 0]
1420I0922 17:03:12.140128 5517 tty.go:112] data length is 13
1421I0922 17:03:12.140133 5517 tty.go:98] tty: trying to read 1 bytes
1422I0922 17:03:12.140138 5517 tty.go:108] tty: read 13/13 [length = 13]
1423I0922 17:03:12.140161 5517 tty.go:98] tty: trying to read 12 bytes
1424I0922 17:03:12.142002 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1425I0922 17:03:12.205623 5517 tty.go:426] trying to input char: 102 and 1 chars
1426I0922 17:03:12.205705 5517 tty.go:133] trying to write to session 1
1427I0922 17:03:12.207666 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1428I0922 17:03:12.210841 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1429I0922 17:03:12.213611 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1430I0922 17:03:12.214572 5517 init_comm.go:68] [console] hyper_event_read
1431I0922 17:03:12.215868 5517 init_comm.go:68] [console] already read 12 bytes data
1432I0922 17:03:12.216631 5517 init_comm.go:68] [console] get length 13
1433I0922 17:03:12.217898 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1434I0922 17:03:12.218772 5517 init_comm.go:68] [console] exec seq 1, seq 1
1435I0922 17:03:12.220725 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1436I0922 17:03:12.222007 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1437I0922 17:03:12.224274 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1438I0922 17:03:12.226649 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1439I0922 17:03:12.227766 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1440I0922 17:03:12.229854 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1441I0922 17:03:12.231069 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1442I0922 17:03:12.233332 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1443I0922 17:03:12.235596 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1444I0922 17:03:12.236500 5517 init_comm.go:68] [console] stderr_loop, seq 0
1445I0922 17:03:12.237490 5517 init_comm.go:68] [console] pts_loop: read 1 data
1446I0922 17:03:12.238619 5517 init_comm.go:68] [console] pts_loop: read -1 data
1447I0922 17:03:12.240583 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1448I0922 17:03:12.242776 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1449I0922 17:03:12.244920 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1450I0922 17:03:12.245848 5517 init_comm.go:68] [console] stdout_loop, seq 1
1451I0922 17:03:12.247288 5517 init_comm.go:68] [console] pts_loop: read -1 data
1452I0922 17:03:12.248401 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1453I0922 17:03:12.250551 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1454I0922 17:03:12.252575 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1455I0922 17:03:12.252834 5517 tty.go:108] tty: read 12/12 [length = 0]
1456I0922 17:03:12.252860 5517 tty.go:112] data length is 13
1457I0922 17:03:12.252865 5517 tty.go:98] tty: trying to read 1 bytes
1458I0922 17:03:12.252871 5517 tty.go:108] tty: read 13/13 [length = 13]
1459I0922 17:03:12.252901 5517 tty.go:98] tty: trying to read 12 bytes
1460I0922 17:03:12.254824 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1461I0922 17:03:12.305934 5517 tty.go:426] trying to input char: 32 and 1 chars
1462I0922 17:03:12.305986 5517 tty.go:133] trying to write to session 1
1463I0922 17:03:12.307095 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1464I0922 17:03:12.309139 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1465I0922 17:03:12.311210 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1466I0922 17:03:12.312042 5517 init_comm.go:68] [console] hyper_event_read
1467I0922 17:03:12.313133 5517 init_comm.go:68] [console] already read 12 bytes data
1468I0922 17:03:12.313889 5517 init_comm.go:68] [console] get length 13
1469I0922 17:03:12.315210 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1470I0922 17:03:12.316155 5517 init_comm.go:68] [console] exec seq 1, seq 1
1471I0922 17:03:12.318042 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1472I0922 17:03:12.319077 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1473I0922 17:03:12.321238 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1474I0922 17:03:12.323391 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1475I0922 17:03:12.324315 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1476I0922 17:03:12.326499 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1477I0922 17:03:12.327541 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1478I0922 17:03:12.329680 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1479I0922 17:03:12.331795 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1480I0922 17:03:12.332735 5517 init_comm.go:68] [console] stderr_loop, seq 0
1481I0922 17:03:12.333702 5517 init_comm.go:68] [console] pts_loop: read 1 data
1482I0922 17:03:12.334729 5517 init_comm.go:68] [console] pts_loop: read -1 data
1483I0922 17:03:12.336714 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1484I0922 17:03:12.339269 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1485I0922 17:03:12.341377 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1486I0922 17:03:12.342260 5517 init_comm.go:68] [console] stdout_loop, seq 1
1487I0922 17:03:12.343268 5517 init_comm.go:68] [console] pts_loop: read -1 data
1488I0922 17:03:12.344327 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1489I0922 17:03:12.346446 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1490I0922 17:03:12.348984 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1491I0922 17:03:12.349280 5517 tty.go:108] tty: read 12/12 [length = 0]
1492I0922 17:03:12.349308 5517 tty.go:112] data length is 13
1493I0922 17:03:12.349312 5517 tty.go:98] tty: trying to read 1 bytes
1494I0922 17:03:12.349318 5517 tty.go:108] tty: read 13/13 [length = 13]
1495I0922 17:03:12.349355 5517 tty.go:98] tty: trying to read 12 bytes
1496I0922 17:03:12.351141 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1497I0922 17:03:12.474556 5517 tty.go:426] trying to input char: 45 and 1 chars
1498I0922 17:03:12.474651 5517 tty.go:133] trying to write to session 1
1499I0922 17:03:12.476500 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1500I0922 17:03:12.479801 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1501I0922 17:03:12.482456 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1502I0922 17:03:12.483422 5517 init_comm.go:68] [console] hyper_event_read
1503I0922 17:03:12.484727 5517 init_comm.go:68] [console] already read 12 bytes data
1504I0922 17:03:12.485657 5517 init_comm.go:68] [console] get length 13
1505I0922 17:03:12.486939 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1506I0922 17:03:12.487899 5517 init_comm.go:68] [console] exec seq 1, seq 1
1507I0922 17:03:12.489996 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1508I0922 17:03:12.491074 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1509I0922 17:03:12.493251 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1510I0922 17:03:12.495444 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1511I0922 17:03:12.496501 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1512I0922 17:03:12.498539 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1513I0922 17:03:12.499578 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1514I0922 17:03:12.501741 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1515I0922 17:03:12.503839 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1516I0922 17:03:12.504777 5517 init_comm.go:68] [console] stderr_loop, seq 0
1517I0922 17:03:12.505963 5517 init_comm.go:68] [console] pts_loop: read 1 data
1518I0922 17:03:12.506989 5517 init_comm.go:68] [console] pts_loop: read -1 data
1519I0922 17:03:12.508901 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1520I0922 17:03:12.511051 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1521I0922 17:03:12.513103 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1522I0922 17:03:12.514300 5517 init_comm.go:68] [console] stdout_loop, seq 1
1523I0922 17:03:12.515383 5517 init_comm.go:68] [console] pts_loop: read -1 data
1524I0922 17:03:12.516408 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1525I0922 17:03:12.518520 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1526I0922 17:03:12.520655 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1527I0922 17:03:12.521075 5517 tty.go:108] tty: read 12/12 [length = 0]
1528I0922 17:03:12.521112 5517 tty.go:112] data length is 13
1529I0922 17:03:12.521120 5517 tty.go:98] tty: trying to read 1 bytes
1530I0922 17:03:12.521129 5517 tty.go:108] tty: read 13/13 [length = 13]
1531I0922 17:03:12.521182 5517 tty.go:98] tty: trying to read 12 bytes
1532I0922 17:03:12.523371 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1533I0922 17:03:12.565306 5517 tty.go:426] trying to input char: 104 and 1 chars
1534I0922 17:03:12.565451 5517 tty.go:133] trying to write to session 1
1535I0922 17:03:12.567626 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1536I0922 17:03:12.570765 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1537I0922 17:03:12.573561 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1538I0922 17:03:12.574510 5517 init_comm.go:68] [console] hyper_event_read
1539I0922 17:03:12.575804 5517 init_comm.go:68] [console] already read 12 bytes data
1540I0922 17:03:12.576745 5517 init_comm.go:68] [console] get length 13
1541I0922 17:03:12.578161 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1542I0922 17:03:12.579174 5517 init_comm.go:68] [console] exec seq 1, seq 1
1543I0922 17:03:12.581303 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1544I0922 17:03:12.582419 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1545I0922 17:03:12.584653 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1546I0922 17:03:12.586871 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1547I0922 17:03:12.587976 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1548I0922 17:03:12.590137 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1549I0922 17:03:12.591251 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1550I0922 17:03:12.593600 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1551I0922 17:03:12.596446 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1552I0922 17:03:12.597715 5517 init_comm.go:68] [console] stderr_loop, seq 0
1553I0922 17:03:12.598875 5517 init_comm.go:68] [console] pts_loop: read 1 data
1554I0922 17:03:12.600130 5517 init_comm.go:68] [console] pts_loop: read -1 data
1555I0922 17:03:12.602106 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1556I0922 17:03:12.604245 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1557I0922 17:03:12.606378 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1558I0922 17:03:12.607303 5517 init_comm.go:68] [console] stdout_loop, seq 1
1559I0922 17:03:12.608602 5517 init_comm.go:68] [console] pts_loop: read -1 data
1560I0922 17:03:12.610339 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1561I0922 17:03:12.612637 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1562I0922 17:03:12.614935 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1563I0922 17:03:12.615272 5517 tty.go:108] tty: read 12/12 [length = 0]
1564I0922 17:03:12.615318 5517 tty.go:112] data length is 13
1565I0922 17:03:12.615323 5517 tty.go:98] tty: trying to read 1 bytes
1566I0922 17:03:12.615329 5517 tty.go:108] tty: read 13/13 [length = 13]
1567I0922 17:03:12.615366 5517 tty.go:98] tty: trying to read 12 bytes
1568I0922 17:03:12.617821 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1569I0922 17:03:12.992677 5517 tty.go:426] trying to input char: 13 and 1 chars
1570I0922 17:03:12.992753 5517 tty.go:133] trying to write to session 1
1571I0922 17:03:12.994746 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1572I0922 17:03:12.997926 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1573I0922 17:03:13.000668 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1574I0922 17:03:13.001764 5517 init_comm.go:68] [console] hyper_event_read
1575I0922 17:03:13.003189 5517 init_comm.go:68] [console] already read 12 bytes data
1576I0922 17:03:13.004216 5517 init_comm.go:68] [console] get length 13
1577I0922 17:03:13.006105 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1578I0922 17:03:13.007111 5517 init_comm.go:68] [console] exec seq 1, seq 1
1579I0922 17:03:13.009192 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1580I0922 17:03:13.010256 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1581I0922 17:03:13.012450 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1582I0922 17:03:13.014822 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1583I0922 17:03:13.015929 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1584I0922 17:03:13.018375 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1585I0922 17:03:13.019541 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1586I0922 17:03:13.021792 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1587I0922 17:03:13.024056 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1588I0922 17:03:13.024963 5517 init_comm.go:68] [console] stderr_loop, seq 0
1589I0922 17:03:13.025975 5517 init_comm.go:68] [console] pts_loop: read 329 data
1590I0922 17:03:13.027079 5517 init_comm.go:68] [console] pts_loop: read -1 data
1591I0922 17:03:13.028963 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1592I0922 17:03:13.031055 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1593I0922 17:03:13.033185 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1594I0922 17:03:13.034122 5517 init_comm.go:68] [console] stdout_loop, seq 1
1595I0922 17:03:13.035151 5517 init_comm.go:68] [console] pts_loop: read -1 data
1596I0922 17:03:13.036237 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1597I0922 17:03:13.038470 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1598I0922 17:03:13.040585 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1599I0922 17:03:13.040883 5517 tty.go:108] tty: read 12/12 [length = 0]
1600I0922 17:03:13.040914 5517 tty.go:112] data length is 341
1601I0922 17:03:13.040922 5517 tty.go:98] tty: trying to read 329 bytes
1602I0922 17:03:13.040937 5517 tty.go:108] tty: read 341/341 [length = 341]
1603I0922 17:03:13.041003 5517 tty.go:98] tty: trying to read 12 bytes
1604I0922 17:03:13.043497 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1605I0922 17:03:17.510162 5517 init_comm.go:251] Send ping message to init
1606I0922 17:03:17.510280 5517 init_comm.go:225] got cmd:12
1607I0922 17:03:17.510304 5517 init_comm.go:316] send command 12 to init, payload: 'null'.
1608I0922 17:03:17.510332 5517 init_comm.go:329] write 12 to init, payload: '
1609
1610 null'.
1611I0922 17:03:17.510342 5517 init_comm.go:334] message sent, set pong timer
1612I0922 17:03:17.513080 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1613I0922 17:03:17.516960 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c600, fd 3. ops 0x61c3e0
1614I0922 17:03:17.519873 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c600, fd 3, 0x61c3e0
1615I0922 17:03:17.520991 5517 init_comm.go:68] [console] hyper_event_read
1616I0922 17:03:17.522308 5517 init_comm.go:68] [console] already read 8 bytes data
1617I0922 17:03:17.523559 5517 init_comm.go:68] [console] hyper send type 14, len 4
1618I0922 17:03:17.523865 5517 init_comm.go:106] read 8/8 [length = 0]
1619I0922 17:03:17.523893 5517 init_comm.go:110] data length is 12
1620I0922 17:03:17.523898 5517 init_comm.go:96] trying to read 4 bytes
1621I0922 17:03:17.524009 5517 init_comm.go:106] read 12/12 [length = 12]
1622I0922 17:03:17.524023 5517 init_comm.go:96] trying to read 8 bytes
1623I0922 17:03:17.524033 5517 init_comm.go:225] got cmd:14
1624I0922 17:03:17.524038 5517 init_comm.go:288] get command NEXT
1625I0922 17:03:17.524054 5517 init_comm.go:291] send 12, receive 8
1626I0922 17:03:17.525330 5517 init_comm.go:68] [console] get length 12
1627I0922 17:03:17.526694 5517 init_comm.go:68] [console] read 4 bytes data, total data 12
1628I0922 17:03:17.528013 5517 init_comm.go:68] [console] hyper send type 14, len 4
1629I0922 17:03:17.528276 5517 init_comm.go:106] read 8/8 [length = 0]
1630I0922 17:03:17.528301 5517 init_comm.go:110] data length is 12
1631I0922 17:03:17.528306 5517 init_comm.go:96] trying to read 4 bytes
1632I0922 17:03:17.528413 5517 init_comm.go:106] read 12/12 [length = 12]
1633I0922 17:03:17.528427 5517 init_comm.go:96] trying to read 8 bytes
1634I0922 17:03:17.528437 5517 init_comm.go:225] got cmd:14
1635I0922 17:03:17.528443 5517 init_comm.go:288] get command NEXT
1636I0922 17:03:17.528446 5517 init_comm.go:291] send 12, receive 12
1637I0922 17:03:17.529521 5517 init_comm.go:68] [console] 0 0 0 c 0 0 0 c 6e 75 6c 6c
1638I0922 17:03:17.530998 5517 init_comm.go:68] [console] hyper_channel_handle, type 12, len 12
1639I0922 17:03:17.532046 5517 init_comm.go:68] [console] hyper send type 9, len 0
1640I0922 17:03:17.532281 5517 init_comm.go:106] read 8/8 [length = 0]
1641I0922 17:03:17.532304 5517 init_comm.go:110] data length is 8
1642I0922 17:03:17.532316 5517 init_comm.go:96] trying to read 8 bytes
1643I0922 17:03:17.532323 5517 init_comm.go:225] got cmd:9
1644I0922 17:03:17.532329 5517 init_comm.go:244] ack got, clear pong timer
1645I0922 17:03:38.975551 5517 init_comm.go:68] [console] random: nonblocking pool is initialized
1646I0922 17:03:45.730105 5517 tty.go:426] trying to input char: 101 and 1 chars
1647I0922 17:03:45.730145 5517 tty.go:133] trying to write to session 1
1648I0922 17:03:45.736493 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1649I0922 17:03:45.736528 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1650I0922 17:03:45.736533 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1651I0922 17:03:45.736536 5517 init_comm.go:68] [console] hyper_event_read
1652I0922 17:03:45.736541 5517 init_comm.go:68] [console] already read 12 bytes data
1653I0922 17:03:45.736555 5517 init_comm.go:68] [console] get length 13
1654I0922 17:03:45.736558 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1655I0922 17:03:45.736560 5517 init_comm.go:68] [console] exec seq 1, seq 1
1656I0922 17:03:45.738342 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1657I0922 17:03:45.739390 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1658I0922 17:03:45.741670 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1659I0922 17:03:45.743815 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1660I0922 17:03:45.744818 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1661I0922 17:03:45.746947 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1662I0922 17:03:45.748004 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1663I0922 17:03:45.750198 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1664I0922 17:03:45.752278 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1665I0922 17:03:45.753204 5517 init_comm.go:68] [console] stderr_loop, seq 0
1666I0922 17:03:45.754212 5517 init_comm.go:68] [console] pts_loop: read 1 data
1667I0922 17:03:45.755162 5517 init_comm.go:68] [console] pts_loop: read -1 data
1668I0922 17:03:45.757081 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1669I0922 17:03:45.759331 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1670I0922 17:03:45.761573 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1671I0922 17:03:45.762525 5517 init_comm.go:68] [console] stdout_loop, seq 1
1672I0922 17:03:45.764053 5517 init_comm.go:68] [console] pts_loop: read -1 data
1673I0922 17:03:45.765267 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1674I0922 17:03:45.767480 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1675I0922 17:03:45.769643 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1676I0922 17:03:45.770040 5517 tty.go:108] tty: read 12/12 [length = 0]
1677I0922 17:03:45.770077 5517 tty.go:112] data length is 13
1678I0922 17:03:45.770082 5517 tty.go:98] tty: trying to read 1 bytes
1679I0922 17:03:45.770087 5517 tty.go:108] tty: read 13/13 [length = 13]
1680I0922 17:03:45.770122 5517 tty.go:98] tty: trying to read 12 bytes
1681I0922 17:03:45.772262 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1682I0922 17:03:45.933435 5517 tty.go:426] trying to input char: 120 and 1 chars
1683I0922 17:03:45.933551 5517 tty.go:133] trying to write to session 1
1684I0922 17:03:45.935301 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1685I0922 17:03:45.938522 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1686I0922 17:03:45.941258 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1687I0922 17:03:45.942243 5517 init_comm.go:68] [console] hyper_event_read
1688I0922 17:03:45.943572 5517 init_comm.go:68] [console] already read 12 bytes data
1689I0922 17:03:45.944310 5517 init_comm.go:68] [console] get length 13
1690I0922 17:03:45.945616 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1691I0922 17:03:45.946554 5517 init_comm.go:68] [console] exec seq 1, seq 1
1692I0922 17:03:45.948595 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1693I0922 17:03:45.949704 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1694I0922 17:03:45.951989 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1695I0922 17:03:45.954289 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1696I0922 17:03:45.955388 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1697I0922 17:03:45.957661 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1698I0922 17:03:45.959031 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1699I0922 17:03:45.961610 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1700I0922 17:03:45.963926 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1701I0922 17:03:45.964971 5517 init_comm.go:68] [console] stderr_loop, seq 0
1702I0922 17:03:45.966072 5517 init_comm.go:68] [console] pts_loop: read 1 data
1703I0922 17:03:45.967204 5517 init_comm.go:68] [console] pts_loop: read -1 data
1704I0922 17:03:45.969213 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1705I0922 17:03:45.971434 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1706I0922 17:03:45.973627 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1707I0922 17:03:45.974732 5517 init_comm.go:68] [console] stdout_loop, seq 1
1708I0922 17:03:45.976966 5517 init_comm.go:68] [console] pts_loop: read -1 data
1709I0922 17:03:45.978449 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1710I0922 17:03:45.980570 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1711I0922 17:03:45.982648 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1712I0922 17:03:45.982945 5517 tty.go:108] tty: read 12/12 [length = 0]
1713I0922 17:03:45.982972 5517 tty.go:112] data length is 13
1714I0922 17:03:45.982977 5517 tty.go:98] tty: trying to read 1 bytes
1715I0922 17:03:45.982983 5517 tty.go:108] tty: read 13/13 [length = 13]
1716I0922 17:03:45.983023 5517 tty.go:98] tty: trying to read 12 bytes
1717I0922 17:03:45.985023 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1718I0922 17:03:46.529808 5517 tty.go:426] trying to input char: 105 and 1 chars
1719I0922 17:03:46.529911 5517 tty.go:133] trying to write to session 1
1720I0922 17:03:46.532208 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1721I0922 17:03:46.535385 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1722I0922 17:03:46.538185 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1723I0922 17:03:46.539070 5517 init_comm.go:68] [console] hyper_event_read
1724I0922 17:03:46.540455 5517 init_comm.go:68] [console] already read 12 bytes data
1725I0922 17:03:46.541183 5517 init_comm.go:68] [console] get length 13
1726I0922 17:03:46.542759 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1727I0922 17:03:46.543712 5517 init_comm.go:68] [console] exec seq 1, seq 1
1728I0922 17:03:46.545651 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1729I0922 17:03:46.547018 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1730I0922 17:03:46.549319 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1731I0922 17:03:46.551628 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1732I0922 17:03:46.552746 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1733I0922 17:03:46.555203 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1734I0922 17:03:46.556288 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1735I0922 17:03:46.558723 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1736I0922 17:03:46.561046 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1737I0922 17:03:46.562211 5517 init_comm.go:68] [console] stderr_loop, seq 0
1738I0922 17:03:46.563197 5517 init_comm.go:68] [console] pts_loop: read 1 data
1739I0922 17:03:46.564220 5517 init_comm.go:68] [console] pts_loop: read -1 data
1740I0922 17:03:46.566182 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1741I0922 17:03:46.568307 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1742I0922 17:03:46.570374 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1743I0922 17:03:46.571245 5517 init_comm.go:68] [console] stdout_loop, seq 1
1744I0922 17:03:46.572253 5517 init_comm.go:68] [console] pts_loop: read -1 data
1745I0922 17:03:46.573287 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1746I0922 17:03:46.575683 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1747I0922 17:03:46.577807 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1748I0922 17:03:46.578096 5517 tty.go:108] tty: read 12/12 [length = 0]
1749I0922 17:03:46.578122 5517 tty.go:112] data length is 13
1750I0922 17:03:46.578127 5517 tty.go:98] tty: trying to read 1 bytes
1751I0922 17:03:46.578133 5517 tty.go:108] tty: read 13/13 [length = 13]
1752I0922 17:03:46.578170 5517 tty.go:98] tty: trying to read 12 bytes
1753I0922 17:03:46.580185 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1754I0922 17:03:46.687731 5517 tty.go:426] trying to input char: 116 and 1 chars
1755I0922 17:03:46.687799 5517 tty.go:133] trying to write to session 1
1756I0922 17:03:46.689867 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1757I0922 17:03:46.692959 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1758I0922 17:03:46.695664 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1759I0922 17:03:46.696579 5517 init_comm.go:68] [console] hyper_event_read
1760I0922 17:03:46.697927 5517 init_comm.go:68] [console] already read 12 bytes data
1761I0922 17:03:46.699177 5517 init_comm.go:68] [console] get length 13
1762I0922 17:03:46.700468 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1763I0922 17:03:46.701376 5517 init_comm.go:68] [console] exec seq 1, seq 1
1764I0922 17:03:46.703298 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1765I0922 17:03:46.704329 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1766I0922 17:03:46.706802 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1767I0922 17:03:46.709275 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1768I0922 17:03:46.710289 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1769I0922 17:03:46.712232 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1770I0922 17:03:46.713333 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1771I0922 17:03:46.715484 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1772I0922 17:03:46.717643 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1773I0922 17:03:46.718635 5517 init_comm.go:68] [console] stderr_loop, seq 0
1774I0922 17:03:46.719651 5517 init_comm.go:68] [console] pts_loop: read 1 data
1775I0922 17:03:46.721020 5517 init_comm.go:68] [console] pts_loop: read -1 data
1776I0922 17:03:46.722934 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1777I0922 17:03:46.725483 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1778I0922 17:03:46.727591 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1779I0922 17:03:46.728491 5517 init_comm.go:68] [console] stdout_loop, seq 1
1780I0922 17:03:46.729569 5517 init_comm.go:68] [console] pts_loop: read -1 data
1781I0922 17:03:46.730980 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1782I0922 17:03:46.733242 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1783I0922 17:03:46.735622 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1784I0922 17:03:46.736026 5517 tty.go:108] tty: read 12/12 [length = 0]
1785I0922 17:03:46.736054 5517 tty.go:112] data length is 13
1786I0922 17:03:46.736059 5517 tty.go:98] tty: trying to read 1 bytes
1787I0922 17:03:46.736065 5517 tty.go:108] tty: read 13/13 [length = 13]
1788I0922 17:03:46.736099 5517 tty.go:98] tty: trying to read 12 bytes
1789I0922 17:03:46.738288 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1790I0922 17:03:46.799632 5517 tty.go:426] trying to input char: 13 and 1 chars
1791I0922 17:03:46.799749 5517 tty.go:133] trying to write to session 1
1792I0922 17:03:46.801793 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1793I0922 17:03:46.804926 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c5c8, fd 4. ops 0x61c3a0
1794I0922 17:03:46.807813 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c5c8, fd 4, 0x61c3a0
1795I0922 17:03:46.809127 5517 init_comm.go:68] [console] hyper_event_read
1796I0922 17:03:46.810471 5517 init_comm.go:68] [console] already read 12 bytes data
1797I0922 17:03:46.811189 5517 init_comm.go:68] [console] get length 13
1798I0922 17:03:46.812468 5517 init_comm.go:68] [console] read 1 bytes data, total data 13
1799I0922 17:03:46.813407 5517 init_comm.go:68] [console] exec seq 1, seq 1
1800I0922 17:03:46.815386 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 4
1801I0922 17:03:46.816474 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1802I0922 17:03:46.818620 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x223e830, fd 6. ops 0x61c540
1803I0922 17:03:46.820879 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x223e830, fd 6, 0x61c540
1804I0922 17:03:46.822066 5517 init_comm.go:68] [console] write_to_stdin, seq 1
1805I0922 17:03:46.824429 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 6, 0x223e830, event 0
1806I0922 17:03:46.825783 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1807I0922 17:03:46.827922 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e8a0, fd 9. ops 0x61c4c0
1808I0922 17:03:46.830185 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e8a0, fd 9, 0x61c4c0
1809I0922 17:03:46.831099 5517 init_comm.go:68] [console] stderr_loop, seq 0
1810I0922 17:03:46.832098 5517 init_comm.go:68] [console] pts_loop: read 2 data
1811I0922 17:03:46.833191 5517 init_comm.go:68] [console] pts_loop: read -1 data
1812I0922 17:03:46.835128 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1813I0922 17:03:46.837287 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x223e868, fd 8. ops 0x61c500
1814I0922 17:03:46.839406 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x223e868, fd 8, 0x61c500
1815I0922 17:03:46.840382 5517 init_comm.go:68] [console] stdout_loop, seq 1
1816I0922 17:03:46.841384 5517 init_comm.go:68] [console] pts_loop: read -1 data
1817I0922 17:03:46.842809 5517 init_comm.go:68] [console] hyper_loop epoll_wait 1
1818I0922 17:03:46.844923 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1819I0922 17:03:46.847020 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1820I0922 17:03:46.847327 5517 tty.go:108] tty: read 12/12 [length = 0]
1821I0922 17:03:46.847366 5517 tty.go:112] data length is 14
1822I0922 17:03:46.847371 5517 tty.go:98] tty: trying to read 2 bytes
1823I0922 17:03:46.847377 5517 tty.go:108] tty: read 14/14 [length = 14]
1824I0922 17:03:46.847417 5517 tty.go:98] tty: trying to read 12 bytes
1825I0922 17:03:46.849481 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1826I0922 17:03:46.850842 5517 init_comm.go:68] [console] pid 596 exit normally, status 0
1827I0922 17:03:46.851892 5517 init_comm.go:68] [console] exec pid 596, pid 596
1828I0922 17:03:46.856461 5517 init_comm.go:68] [console] hyper_handle_exec_exit exec exit pid 596, seq 1, container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112
1829I0922 17:03:46.857763 5517 init_comm.go:68] [console] still have 3 user of exec
1830I0922 17:03:46.859311 5517 init_comm.go:68] [console] container init process 596
1831I0922 17:03:46.860981 5517 init_comm.go:68] [console] hyper_loop epoll_wait -1
1832I0922 17:03:46.862995 5517 init_comm.go:68] [console] hyper_loop epoll_wait 3
1833I0922 17:03:46.866654 5517 init_comm.go:68] [console] hyper_handle_event get event 16, he 0x223e8a0, fd 9. ops 0x61c4c0
1834I0922 17:03:46.868962 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLHUP, he 0x223e8a0, fd 9, 0x61c4c0
1835I0922 17:03:46.869674 5517 init_comm.go:68] [console] stderr_hup
1836I0922 17:03:46.870474 5517 init_comm.go:68] [console] pts_hup, seq 1
1837I0922 17:03:46.871597 5517 init_comm.go:68] [console] still have 2 user of exec
1838I0922 17:03:46.873845 5517 init_comm.go:68] [console] hyper_handle_event get event 16, he 0x223e868, fd 8. ops 0x61c500
1839I0922 17:03:46.876221 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLHUP, he 0x223e868, fd 8, 0x61c500
1840I0922 17:03:46.877143 5517 init_comm.go:68] [console] stdout_hup
1841I0922 17:03:46.879056 5517 init_comm.go:68] [console] pts_hup, seq 1
1842I0922 17:03:46.880378 5517 init_comm.go:68] [console] still have 1 user of exec
1843I0922 17:03:46.882778 5517 init_comm.go:68] [console] hyper_handle_event get event 16, he 0x223e830, fd 6. ops 0x61c540
1844I0922 17:03:46.885077 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLHUP, he 0x223e830, fd 6, 0x61c540
1845I0922 17:03:46.885814 5517 init_comm.go:68] [console] stdin_hup
1846I0922 17:03:46.886585 5517 init_comm.go:68] [console] pts_hup, seq 1
1847I0922 17:03:46.888324 5517 init_comm.go:68] [console] last user of exec exit, release
1848I0922 17:03:46.890244 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 5
1849I0922 17:03:46.891568 5517 init_comm.go:68] [console] hyper_release_exec exit code 0
1850I0922 17:03:46.893955 5517 init_comm.go:68] [console] hyper_release_exec container init exited automatically, remains 1
1851I0922 17:03:46.895102 5517 init_comm.go:68] [console] hyper send type 13, len 4
1852I0922 17:03:46.895505 5517 init_comm.go:106] read 8/8 [length = 0]
1853I0922 17:03:46.895533 5517 init_comm.go:110] data length is 12
1854I0922 17:03:46.895537 5517 init_comm.go:96] trying to read 4 bytes
1855I0922 17:03:46.895695 5517 init_comm.go:106] read 12/12 [length = 12]
1856I0922 17:03:46.895734 5517 init_comm.go:96] trying to read 8 bytes
1857I0922 17:03:46.895763 5517 init_comm.go:225] got cmd:13
1858I0922 17:03:46.895774 5517 init_comm.go:281] Pod finished, returned 1 values
1859I0922 17:03:46.895788 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 4(EVENT_POD_FINISH)
1860I0922 17:03:46.895802 5517 context.go:260] VM vm-iGMHsoEeXV: state change from RUNNING to 'TERMINATING'
1861I0922 17:03:46.895810 5517 init_comm.go:225] got cmd:4
1862I0922 17:03:46.895862 5517 init_comm.go:316] send command 4 to init, payload: 'null'.
1863I0922 17:03:46.895877 5517 init_comm.go:329] write 12 to init, payload: '
1864 null'.
1865I0922 17:03:46.895931 5517 init_comm.go:334] message sent, set pong timer
1866I0922 17:03:46.897140 5517 init_comm.go:68] [console] fopen /proc/328/status
1867I0922 17:03:46.898630 5517 init_comm.go:68] [console] find sigign 0000000000000000
1868I0922 17:03:46.899404 5517 init_comm.go:68] [console] mask is 0
1869I0922 17:03:46.907660 5517 init_comm.go:68] [console] XFS (sda): Unmounting Filesystem
1870I0922 17:03:46.917141 5517 init_comm.go:68] [console] net device eth0
1871I0922 17:03:46.919272 5517 init_comm.go:68] [console] net device sys path is /sys/class/net/eth0/ifindex
1872I0922 17:03:46.920184 5517 init_comm.go:68] [console] get ifindex 2
1873I0922 17:03:46.921013 5517 init_comm.go:68] [console] net device eth0
1874I0922 17:03:46.922822 5517 init_comm.go:68] [console] net device sys path is /sys/class/net/eth0/ifindex
1875I0922 17:03:46.923588 5517 init_comm.go:68] [console] get ifindex 2
1876I0922 17:03:46.925036 5517 init_comm.go:68] [console] interface get netamsk 24 255.255.255.0
1877I0922 17:03:46.928855 5517 init_comm.go:68] [console] get net sys path /sys//devices/pci0000:00/0000:00:05.0/virtio3/net/eth0/../../../remove
1878I0922 17:03:46.951401 5517 init_comm.go:68] [console] open /tmp/hyper/resolv.conf failed: No such file or directory
1879I0922 17:03:46.952474 5517 init_comm.go:68] [console] hyper_loop epoll_wait 2
1880I0922 17:03:46.954979 5517 init_comm.go:68] [console] hyper_handle_event get event 4, he 0x61c5c8, fd 4. ops 0x61c3a0
1881I0922 17:03:46.957123 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, he 0x61c5c8, fd 4, 0x61c3a0
1882I0922 17:03:46.957442 5517 tty.go:108] tty: read 12/12 [length = 0]
1883I0922 17:03:46.957488 5517 tty.go:112] data length is 12
1884I0922 17:03:46.957496 5517 tty.go:169] session 1 closed by peer, close pty
1885I0922 17:03:46.957500 5517 tty.go:98] tty: trying to read 12 bytes
1886I0922 17:03:46.957514 5517 tty.go:108] tty: read 12/12 [length = 0]
1887I0922 17:03:46.957517 5517 tty.go:112] data length is 13
1888I0922 17:03:46.957519 5517 tty.go:98] tty: trying to read 1 bytes
1889I0922 17:03:46.957523 5517 tty.go:108] tty: read 13/13 [length = 13]
1890I0922 17:03:46.957529 5517 tty.go:176] session 1, exit code 0
1891I0922 17:03:46.957537 5517 context.go:210] found container 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112 whose session is 1 at 0
1892I0922 17:03:46.957559 5517 tty.go:248] Close tty
1893I0922 17:03:46.957568 5517 tty.go:248] Close tty
1894I0922 17:03:46.957573 5517 tty.go:98] tty: trying to read 12 bytes
1895I0922 17:03:46.957578 5517 tty.go:37] tty is closed
18962016/09/22 17:03:46 http: response.WriteHeader on hijacked connection
1897I0922 17:03:46.957639 5517 tty.go:411] a stdin closed, read unix /var/run/hyper.sock->@: use of closed network connection
1898I0922 17:03:46.958128 5517 server.go:152] Calling GET /v0.6.2/list
1899I0922 17:03:46.958186 5517 pod_routes.go:52] List type is container, specified pod: [pod-OUfBbohkAW], specified vm: [], list auxiliary pod: false
1900I0922 17:03:46.958572 5517 server.go:152] Calling GET /v0.6.2/exitcode
1901I0922 17:03:46.958609 5517 exec.go:16] Get container id 7f7b92a939a4a813c81f2711c98c4811f2ad8ad3cab4140926be247b73fa7112, exec id
1902I0922 17:03:46.960400 5517 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61c5c8, event 1
1903I0922 17:03:46.962630 5517 init_comm.go:68] [console] hyper_handle_event get event 1, he 0x61c600, fd 3. ops 0x61c3e0
1904I0922 17:03:46.964901 5517 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, he 0x61c600, fd 3, 0x61c3e0
1905I0922 17:03:46.965734 5517 init_comm.go:68] [console] hyper_event_read
1906I0922 17:03:46.966817 5517 init_comm.go:68] [console] already read 8 bytes data
1907I0922 17:03:46.967911 5517 init_comm.go:68] [console] hyper send type 14, len 4
1908I0922 17:03:46.968193 5517 init_comm.go:106] read 8/8 [length = 0]
1909I0922 17:03:46.968218 5517 init_comm.go:110] data length is 12
1910I0922 17:03:46.968223 5517 init_comm.go:96] trying to read 4 bytes
1911I0922 17:03:46.968331 5517 init_comm.go:106] read 12/12 [length = 12]
1912I0922 17:03:46.968355 5517 init_comm.go:96] trying to read 8 bytes
1913I0922 17:03:46.968364 5517 init_comm.go:225] got cmd:14
1914I0922 17:03:46.968368 5517 init_comm.go:288] get command NEXT
1915I0922 17:03:46.968372 5517 init_comm.go:291] send 12, receive 8
1916I0922 17:03:46.968958 5517 init_comm.go:68] [console] get length 12
1917I0922 17:03:46.970236 5517 init_comm.go:68] [console] read 4 bytes data, total data 12
1918I0922 17:03:46.971295 5517 init_comm.go:68] [console] hyper send type 14, len 4
1919I0922 17:03:46.971545 5517 init_comm.go:106] read 8/8 [length = 0]
1920I0922 17:03:46.971568 5517 init_comm.go:110] data length is 12
1921I0922 17:03:46.971573 5517 init_comm.go:96] trying to read 4 bytes
1922I0922 17:03:46.971674 5517 init_comm.go:106] read 12/12 [length = 12]
1923I0922 17:03:46.971687 5517 init_comm.go:96] trying to read 8 bytes
1924I0922 17:03:46.971694 5517 init_comm.go:225] got cmd:14
1925I0922 17:03:46.971698 5517 init_comm.go:288] get command NEXT
1926I0922 17:03:46.971701 5517 init_comm.go:291] send 12, receive 12
1927I0922 17:03:46.972750 5517 init_comm.go:68] [console] 0 0 0 4 0 0 0 c 6e 75 6c 6c
1928I0922 17:03:46.974160 5517 init_comm.go:68] [console] hyper_channel_handle, type 4, len 12
1929I0922 17:03:46.975272 5517 init_comm.go:68] [console] get DESTROYPOD message
1930I0922 17:03:46.976397 5517 init_comm.go:68] [console] hyper send type 9, len 0
1931I0922 17:03:46.976635 5517 init_comm.go:106] read 8/8 [length = 0]
1932I0922 17:03:46.976659 5517 init_comm.go:110] data length is 8
1933I0922 17:03:46.976673 5517 init_comm.go:96] trying to read 8 bytes
1934I0922 17:03:46.976685 5517 init_comm.go:225] got cmd:9
1935I0922 17:03:46.976691 5517 init_comm.go:229] got response of shutdown command, last round of command to init
1936I0922 17:03:46.976705 5517 init_comm.go:244] ack got, clear pong timer
1937I0922 17:03:46.976715 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 31(COMMAND_ACK)
1938I0922 17:03:46.976729 5517 vm_states.go:642] [Terminating] Got reply to &{4 <nil> <nil> [] 859538263904}: ''
1939I0922 17:03:46.976742 5517 vm_states.go:644] POD destroyed
1940I0922 17:03:46.976753 5517 qmp_handler.go:296] got new session
1941I0922 17:03:46.976768 5517 qmp_handler.go:225] Begin process command session
1942I0922 17:03:46.976792 5517 qmp_handler.go:243] sending command (1) {"execute":"quit"}
1943I0922 17:03:46.976994 5517 qmp_handler.go:103] got a message {"return": {}}
1944I0922 17:03:46.977034 5517 qmp_handler.go:103] got a message {"timestamp": {"seconds": 1474535026, "microseconds": 976966}, "event": "SHUTDOWN"}
1945I0922 17:03:46.977046 5517 qmp_handler.go:107] got event: SHUTDOWN
1946I0922 17:03:46.977054 5517 qmp_handler.go:152] Shutdown, quit QMP receiver
1947I0922 17:03:46.977062 5517 qmp_handler.go:323] got QMP event SHUTDOWN
1948I0922 17:03:46.977066 5517 qmp_handler.go:325] got QMP shutdown event, quit...
1949I0922 17:03:46.977072 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 1(EVENT_VM_EXIT)
1950I0922 17:03:46.977077 5517 vm_states.go:626] Got VM shutdown event while terminating, go to cleaning up
1951I0922 17:03:46.977081 5517 vm_states.go:36] VM has exit...
1952I0922 17:03:46.977089 5517 devicemap.go:492] remove network card 0: 192.168.123.2
1953I0922 17:03:46.977095 5517 context.go:260] VM vm-iGMHsoEeXV: state change from TERMINATING to 'DESTROYING'
1954I0922 17:03:46.977123 5517 hypervisor.go:29] vm vm-iGMHsoEeXV: main event loop got message 13(EVENT_INTERFACE_DELETE)
1955I0922 17:03:46.977127 5517 devicemap.go:446] interface 0 released
1956I0922 17:03:46.977131 5517 vm_states.go:355] Unplug interface return with true
1957I0922 17:03:46.977134 5517 context.go:247] no more device to release/remove/umount, quit
1958I0922 17:03:46.977148 5517 qemu_process.go:86] quit watch dog.
1959E0922 17:03:47.011327 5517 init_comm.go:99] read init data failed
1960E0922 17:03:47.011337 5517 tty.go:101] read tty data failed
1961I0922 17:03:47.011675 5517 tty.go:162] tty socket closed, quit the reading goroutine EOF
1962I0922 17:03:47.011685 5517 tty.go:129] tty chan closed, quit sent goroutine
1963I0922 17:03:47.011379 5517 tty.go:457] Input byte chan closed, close the output string chan
1964I0922 17:03:47.011693 5517 init_comm.go:70] console output end
1965I0922 17:03:47.029043 5517 pod.go:852] cleanupEtcHost for pod-OUfBbohkAW
1966I0922 17:03:47.029071 5517 etchosts.go:84] cleanupHosts /var/lib/hyper/hosts/pod-OUfBbohkAW, /var/lib/hyper/hosts/pod-OUfBbohkAW/hosts
1967I0922 17:03:51.006216 5517 server.go:152] Calling GET /v0.6.2/list
1968I0922 17:03:51.006266 5517 pod_routes.go:52] List type is pod, specified pod: [], specified vm: [], list auxiliary pod: false