hyperhq/hyperd

hyperstart continue crash in frakti CI

Closed this issue · 1 comments

It's latest hyperd master.

[k8s.io] Streaming runtime should support streaming interfaces 
  runtime should support attach [Conformance]
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:81
[BeforeEach] [k8s.io] Streaming
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:50
[BeforeEach] [k8s.io] Streaming
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:50
[It] runtime should support attach [Conformance]
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:81
I1213 18:32:08.412134   32081 manager.go:208] RunPodSandbox from runtime service with request &RunPodSandboxRequest{Config:&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6,Uid:cri-test-uided1c8410-e033-11e7-8844-42010a1400d6,Namespace:cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6,Attempt:2,},Hostname:,LogDirectory:,DnsConfig:nil,PortMappings:[],Labels:map[string]string{},Annotations:map[string]string{},Linux:&LinuxPodSandboxConfig{CgroupParent:,SecurityContext:nil,Sysctls:map[string]string{},},},}
E1213 18:32:08.463102   24089 json.go:165] SB[vm-JKZsGwBBAW] Cannot connect to ctl socket unix:///var/run/hyper/vm-JKZsGwBBAW/hyper.sock: dial unix /var/run/hyper/vm-JKZsGwBBAW/hyper.sock: connect: no such file or directory
E1213 18:32:08.463112   24089 vm_console.go:69] SB[vm-JKZsGwBBAW] failed to connected to /var/run/hyper/vm-JKZsGwBBAW/console.sock: dial unix /var/run/hyper/vm-JKZsGwBBAW/console.sock: connect: no such file or directory
E1213 18:32:08.463135   24089 json.go:442] SB[vm-JKZsGwBBAW] Cannot connect to stream socket unix:///var/run/hyper/vm-JKZsGwBBAW/tty.sock: dial unix /var/run/hyper/vm-JKZsGwBBAW/tty.sock: connect: no such file or directory
E1213 18:32:08.463144   24089 qmp_handler.go:164] failed to connected to /var/run/hyper/vm-JKZsGwBBAW/qmp.sock: dial unix /var/run/hyper/vm-JKZsGwBBAW/qmp.sock: connect: no such file or directory
E1213 18:32:08.463168   24089 qmp_handler.go:364] QMP initialize failed
I1213 18:32:08.463191   24089 hypervisor.go:31] SB[vm-JKZsGwBBAW] main event loop exiting
W1213 18:32:10.015748   24089 qmp_handler.go:284] Initializer Timeout.
E1213 18:32:10.015932   24089 qmp_handler.go:371] QMP initialize timeout
E1213 18:32:10.111063   24089 json.go:442] SB[vm-UediJByTAa] Cannot connect to stream socket unix:///var/run/hyper/vm-UediJByTAa/tty.sock: dial unix /var/run/hyper/vm-UediJByTAa/tty.sock: connect: no such file or directory
E1213 18:32:10.111123   24089 qmp_handler.go:164] failed to connected to /var/run/hyper/vm-UediJByTAa/qmp.sock: dial unix /var/run/hyper/vm-UediJByTAa/qmp.sock: connect: no such file or directory
E1213 18:32:10.111165   24089 qmp_handler.go:364] QMP initialize failed
I1213 18:32:10.111195   24089 hypervisor.go:31] SB[vm-UediJByTAa] main event loop exiting
E1213 18:32:10.111233   24089 json.go:165] SB[vm-UediJByTAa] Cannot connect to ctl socket unix:///var/run/hyper/vm-UediJByTAa/hyper.sock: dial unix /var/run/hyper/vm-UediJByTAa/hyper.sock: connect: no such file or directory
E1213 18:32:10.117931   24089 vm_console.go:69] SB[vm-UediJByTAa] failed to connected to /var/run/hyper/vm-UediJByTAa/console.sock: dial unix /var/run/hyper/vm-UediJByTAa/console.sock: connect: no such file or directory
I1213 18:32:10.477287   32081 sandbox.go:106] Get container interfaces in netns "/var/run/netns/cni-9b93ea70-2590-1267-c787-e322e220e0e7": []*hyper.containerInterface{(*hyper.containerInterface)(0xc420c4aaf0)}
I1213 18:32:10.498617   24089 pod.go:14] PodCreate with request podSpec:<id:"k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d" labels:<key:"HOSTBRIDGE" value:"br1937cbf5" > labels:<key:"NETNS" value:"/var/run/netns/cni-9b93ea70-2590-1267-c787-e322e220e0e7" > resource:<vcpu:1 memory:64 > interfaces:<bridge:"br1937cbf5" ip:"10.30.0.16/16" ifname:"tap1937cbf5" mac:"2e:5b:82:de:67:ab" gateway:"10.30.0.1" > > 
I1213 18:32:10.499311   24089 factory.go:95] configuring log driver [json-file] for k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d
I1213 18:32:10.499473   24089 sandbox.go:27] get sandbox from factory: CPU: 1, Memory 64
I1213 18:32:10.500376   24089 vm.go:788] VM[vm-WnpcdpKZBG] GetVm succeeded
I1213 18:32:10.501125   24089 vm_states.go:301] SB[vm-WnpcdpKZBG] startPod: &json.Pod{Hostname:"k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-88", DeprecatedContainers:[]json.Container(nil), DeprecatedInterfaces:[]json.NetworkInf(nil), Dns:[]string(nil), DnsOptions:[]string(nil), DnsSearch:[]string(nil), DeprecatedRoutes:[]json.Route(nil), ShareDir:"share_dir", PortmappingWhiteLists:(*json.PortmappingWhiteList)(0xc420fe8780)}
I1213 18:32:10.500860   24089 qemu_amd64.go:38] kvm not exist change to no kvm mode
I1213 18:32:10.502326   24089 qemu_process.go:138] cmdline arguments: -machine pc-i440fx-2.1,usb=off -cpu core2duo -kernel /tmp/src/github.com/hyperhq/hyperstart/build/arch/x86_64/kernel -initrd /tmp/src/github.com/hyperhq/hyperstart/build/hyper-initrd.img -append console=ttyS0 panic=1 no_timer_check iommu=off clocksource=acpi_pm notsc -realtime mlock=off -no-user-config -nodefaults -no-hpet -rtc base=utc,clock=vm,driftfix=slew -no-reboot -display none -boot strict=on -m size=64,slots=1,maxmem=32768M -smp cpus=1,maxcpus=8 -numa node,nodeid=0,cpus=0-7,mem=64 -qmp unix:/var/run/hyper/vm-WnpcdpKZBG/qmp.sock,server,nowait -serial unix:/var/run/hyper/vm-WnpcdpKZBG/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-WnpcdpKZBG/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-WnpcdpKZBG/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-WnpcdpKZBG/share_dir,security_model=none -device virtio-9p-pci,fsdev=virtio9p,mount_tag=share_dir -daemonize -pidfile /var/run/hyper/vm-WnpcdpKZBG/pidfile -D /var/log/hyper/qemu/vm-WnpcdpKZB.log
I1213 18:32:10.500933   24089 vm_console.go:56] SB[vm-WnpcdpKZBG] fail to enable vmLogd: dial unix /var/run/vmlogd.sock: connect: no such file or directory
I1213 18:32:10.500944   24089 hypervisor.go:41] SB[vm-WnpcdpKZBG] watch hyperstart
I1213 18:32:10.502414   24089 qemu_process.go:139] qemu log file: /var/log/hyper/qemu/vm-WnpcdpKZB.log
I1213 18:32:10.502596   24089 hypervisor.go:44] SB[vm-WnpcdpKZBG] issue VERSION request for keep-alive test
E1213 18:32:10.503471   24089 qemu_process.go:155] /usr/bin/qemu-system-x86_64: error while loading shared libraries: libxenctrl-4.4.so: cannot open shared object file: No such file or directory
E1213 18:32:10.503484   24089 qemu_process.go:159] exit status 127
I1213 18:32:10.503516   24089 hypervisor.go:23] SB[vm-WnpcdpKZBG] main event loop got message 12(ERROR_VM_START_FAILED)
I1213 18:32:10.503530   24089 vm_states.go:361] SB[vm-WnpcdpKZBG] VM has exit, or not started at all (12)
I1213 18:32:10.503543   24089 context.go:199] SB[vm-WnpcdpKZBG] VmContext Close()
I1213 18:32:10.503553   24089 json.go:93] SB[vm-WnpcdpKZBG] close jsonBasedHyperstart
I1213 18:32:10.503583   24089 decommission.go:526] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] got vm exit event
I1213 18:32:10.503592   24089 decommission.go:576] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] umount all containers and volumes, release IP addresses
I1213 18:32:10.503604   24089 etchosts.go:97] cleanupHosts /var/lib/hyper/hosts/k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d, /var/lib/hyper/hosts/k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d/hosts
I1213 18:32:10.503623   24089 etchosts.go:101] cannot find /var/lib/hyper/hosts/k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d/hosts
E1213 18:32:10.503628   24089 vm_states.go:309] SB[vm-WnpcdpKZBG] Start POD failed: hyperstart closed
I1213 18:32:10.503650   24089 provision.go:277] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] sandbox init result: &errors.errorString{s:"hyperstart closed"}
I1213 18:32:10.503657   24089 decommission.go:555] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] sandbox info removed from db
I1213 18:32:10.503663   24089 decommission.go:561] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] tag pod as stopped
I1213 18:32:10.503669   24089 decommission.go:568] Pod[k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d] pod stopped
E1213 18:32:10.503662   24089 run.go:34] k8s_POD.2_create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6_cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6_cri-test-uided1c8410-e033-11e7-8844-42010a1400d6_95af680d: failed to add pod: hyperstart closed
E1213 18:32:10.503675   24089 json.go:601] SB[vm-WnpcdpKZBG] get hyperstart API version error: hyperstart closed
E1213 18:32:10.503678   24089 pod.go:18] CreatePod failed: hyperstart closed
W1213 18:32:10.503682   24089 hypervisor.go:47] SB[vm-WnpcdpKZBG] keep-alive test end with error: hyperstart closed
E1213 18:32:10.503886   32081 sandbox.go:141] Create pod for sandbox "&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:create-PodSandbox-for-container-ed1c83e5-e033-11e7-8844-42010a1400d6,Uid:cri-test-uided1c8410-e033-11e7-8844-42010a1400d6,Namespace:cri-test-namespaceed1c8430-e033-11e7-8844-42010a1400d6,Attempt:2,},Hostname:,LogDirectory:,DnsConfig:nil,PortMappings:[],Labels:map[string]string{},Annotations:map[string]string{},Linux:&LinuxPodSandboxConfig{CgroupParent:,SecurityContext:nil,Sysctls:map[string]string{},},}" failed: rpc error: code = Unknown desc = hyperstart closed
E1213 18:32:10.680745   32081 manager.go:214] RunPodSandbox from hyper runtime service failed: rpc error: code = Unknown desc = hyperstart closed
E1213 18:32:10.680989     515 remote_runtime.go:92] RunPodSandbox from runtime service failed: rpc error: code = Unknown desc = hyperstart closed
Dec 13 18:32:10.681: INFO: Unexpected error occurred: rpc error: code = Unknown desc = hyperstart closed
[AfterEach] runtime should support streaming interfaces
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:59
STEP: stop PodSandbox
I1213 18:32:10.681988   32081 manager.go:226] StopPodSandbox from runtime service with request &StopPodSandboxRequest{PodSandboxId:,}
I1213 18:32:10.682256   24089 info.go:16] PodInfo with request 
E1213 18:32:10.682283   24089 info.go:20] GetPodInfo error: Can not get Pod info with pod ID()
E1213 18:32:10.682416   32081 sandbox.go:343] GetPodInfo for  failed: rpc error: code = Unknown desc = Can not get Pod info with pod ID()
W1213 18:32:10.682441   32081 sandbox.go:253] Failed to get checkpoint for sandbox "": open /var/lib/frakti/sandbox: no such file or directory
I1213 18:32:10.682759   24089 info.go:16] PodInfo with request 
E1213 18:32:10.682783   24089 info.go:20] GetPodInfo error: Can not get Pod info with pod ID()
STEP: delete PodSandbox
I1213 18:32:10.702470   32081 manager.go:240] RemovePodSandbox from runtime service with request &RemovePodSandboxRequest{PodSandboxId:,}
I1213 18:32:10.702830   24089 pod.go:43] PodRemove with request 
E1213 18:32:10.702960   32081 sandbox.go:327] Remove pod  failed: rpc error: code = Unknown desc = PodID is required for PodRemove
E1213 18:32:10.702977   32081 manager.go:245] RemovePodSandbox from hyper runtime service failed: rpc error: code = Unknown desc = PodID is required for PodRemove
E1213 18:32:10.703097     515 remote_runtime.go:132] RemovePodSandbox "" from runtime service failed: rpc error: code = Unknown desc = PodID is required for PodRemove
[AfterEach] [k8s.io] Streaming
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:51
• Failure [2.292 seconds]
[k8s.io] Streaming
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:72
  runtime should support streaming interfaces
  /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:55
    runtime should support attach [Conformance] [It]
    /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/streaming.go:81
    failed to create PodSandbox: rpc error: code = Unknown desc = hyperstart closed
    Expected error:
        <*status.statusError | 0xc420308cc0>: {
            Code: 2,
            Message: "hyperstart closed",
            Details: nil,
        }
        rpc error: code = Unknown desc = hyperstart closed
    not to have occurred
    /home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/util.go:147
------------------------------
S

https://travis-ci.org/kubernetes/frakti/jobs/315962132

duplicated with #690