search

kuasar-io / kuasar

A multi-sandbox container runtime that provides cloud-native, all-scenario multiple sandbox container solutions.
https://kuasar.io
Apache License 2.0
1.27k stars 92 forks source link

vmm sandboxer example cannot work for me #29

Closed renzhengeek closed 1 year ago

renzhengeek commented 1 year ago

What happened?

Hi developers,

I followd “Quick start” doc: https://github.com/kuasar-io/kuasar#quick-start to play the vmm sandboxer, and got stumbled at the last steps. Please help to debug the issue:-)

crictl -D -r unix:///run/containerd/containerd.sock run --runtime=vmm container.json pod.json failed at starting containers:

DEBU[0000] get image connection
DEBU[0000] get runtime connection
DEBU[0000] RunPodSandboxRequest: &RunPodSandboxRequest{Config:&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:yc-test-sandbox-4,Uid:,Namespace:default,Att
empt:0,},Hostname:,LogDirectory:/tmp,DnsConfig:nil,PortMappings:[]*PortMapping{},Labels:map[string]string{},Annotations:map[string]string{},Linux:&LinuxPodSan
dboxConfig{CgroupParent:,SecurityContext:&LinuxSandboxSecurityContext{NamespaceOptions:&NamespaceOption{Network:NODE,Pid:CONTAINER,Ipc:POD,TargetId:,UsernsOpt
ions:nil,},SelinuxOptions:nil,RunAsUser:nil,ReadonlyRootfs:false,SupplementalGroups:[],Privileged:false,SeccompProfilePath:,RunAsGroup:nil,Seccomp:nil,Apparmo
r:nil,},Sysctls:map[string]string{},Overhead:nil,Resources:nil,},Windows:nil,},RuntimeHandler:vmm,}
DEBU[0000] RunPodSandboxResponse: 9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd
DEBU[0000] PullImageRequest: &PullImageRequest{Image:&ImageSpec{Image:ubuntu:latest,Annotations:map[string]string{},},Aut
h:nil,SandboxConfig:&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:yc-test-sandbox-4,Uid:,Namespace:default,Attempt:0,},Hostname:,LogDirectory:/tmp,DnsCo
nfig:nil,PortMappings:[]*PortMapping{},Labels:map[string]string{},Annotations:map[string]string{},Linux:&LinuxPodSandboxConfig{CgroupParent:,SecurityContext:&
LinuxSandboxSecurityContext{NamespaceOptions:&NamespaceOption{Network:NODE,Pid:CONTAINER,Ipc:POD,TargetId:,UsernsOptions:nil,},SelinuxOptions:nil,RunAsUser:ni
l,ReadonlyRootfs:false,SupplementalGroups:[],Privileged:false,SeccompProfilePath:,RunAsGroup:nil,Seccomp:nil,Apparmor:nil,},Sysctls:map[string]string{},Overhe
ad:nil,Resources:nil,},Windows:nil,},}
DEBU[0015] PullImageResponse: &PullImageResponse{ImageRef:sha256:ba6acccedd2923aee4c2acc6a23780b14ed4b8a5fa4e14e252a23b846df9b6c1,}
DEBU[0015] CreateContainerRequest: &CreateContainerRequest{PodSandboxId:9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd,Config:&ContainerConf
ig{Metadata:&ContainerMetadata{Name:ubuntu-1,Attempt:0,},Image:&ImageSpec{Image:ubuntu:latest,Annotations:map[string]stri
ng{},},Command:[/bin/sh -c while true; do echo `date`; sleep 1; done],Args:[],WorkingDir:,Envs:[]*KeyValue{},Mounts:[]*Mount{},Devices:[]*Device{},Labels:map[
string]string{},Annotations:map[string]string{},LogPath:ubuntu.log,Stdin:false,StdinOnce:false,Tty:false,Linux:&LinuxContainerConfig{Resources:nil,SecurityCon
text:&LinuxContainerSecurityContext{Capabilities:nil,Privileged:false,NamespaceOptions:&NamespaceOption{Network:NODE,Pid:CONTAINER,Ipc:POD,TargetId:,UsernsOpt
ions:nil,},SelinuxOptions:nil,RunAsUser:nil,RunAsUsername:,ReadonlyRootfs:false,SupplementalGroups:[],ApparmorProfile:,SeccompProfilePath:,NoNewPrivs:false,Ru
nAsGroup:nil,MaskedPaths:[],ReadonlyPaths:[],Seccomp:nil,Apparmor:nil,},},Windows:nil,CDIDevices:[]*CDIDevice{},},SandboxConfig:&PodSandboxConfig{Metadata:&Po
dSandboxMetadata{Name:yc-test-sandbox-4,Uid:,Namespace:default,Attempt:0,},Hostname:,LogDirectory:/tmp,DnsConfig:nil,PortMappings:[]*PortMapping{},Labels:map[
string]string{},Annotations:map[string]string{},Linux:&LinuxPodSandboxConfig{CgroupParent:,SecurityContext:&LinuxSandboxSecurityContext{NamespaceOptions:&Name
spaceOption{Network:NODE,Pid:CONTAINER,Ipc:POD,TargetId:,UsernsOptions:nil,},SelinuxOptions:nil,RunAsUser:nil,ReadonlyRootfs:false,SupplementalGroups:[],Privi
leged:false,SeccompProfilePath:,RunAsGroup:nil,Seccomp:nil,Apparmor:nil,},Sysctls:map[string]string{},Overhead:nil,Resources:nil,},Windows:nil,},}

DEBU[0015] CreateContainerResponse: ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845
E0616 09:00:55.312186  235653 remote_runtime.go:326] "StartContainer from runtime service failed" err="rpc error: code = DeadlineExceeded desc = context deadl
ine exceeded" containerID="ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845"
FATA[0017] running container: starting the container "ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845": rpc error: code = DeadlineExceeded de
sc = context deadline exceeded

vmm-sandboxer output: (not full debug log, only key infos) RUST_LOG="debug" /root/kuasar/vmm/sandbox/target/debug/vmm-sandboxer --listen /run/vmm-sandboxer.sock --dir /run/kuasar-vmm

[2023-06-16T01:00:37.850113Z DEBUG vmm_sandboxer::cloud_hypervisor] start virtiofsd with cmdline: Command { std: "/usr/local/bin/virtiofsd" "--log-level" "deb
ug" "--cache" "never" "--thread-pool-size" "4" "--socket-path" "/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/virtiofs.sock
" "--shared-dir" "/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd" "--sandbox" "none", kill_on_drop: false }
[2023-06-16T01:00:37.850516Z DEBUG vmm_sandboxer::cloud_hypervisor] start cloud hypervisor with cmdline: Command { std: "/usr/local/bin/cloud-hypervisor" "--a
pi-socket" "/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/api.sock" "--cpus" "boot=1,affinity=,features=" "--memory" "size=
1073741824,shared=on,hugepages=off" "--kernel" "/var/lib/kuasar/vmlinux.bin" "--cmdline" "console=hvc0 root=/dev/pmem0p1 rootflags=data=ordered,errors=remount
-ro ro rootfstype=ext4 task.sharefs_type=virtiofs  task.log_level=debug" "--pmem" "id=rootfs,file=/var/lib/kuasar/kuasar.img,discard_writes=on" "--rng" "src=/
dev/urandom" "--vsock" "cid=3,socket=/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/task.vsock,id=vsock" "--console" "file=/
tmp/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd-task.log" "--fs" "tag=kuasar,socket=/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c
53b1c7fee69dfd33effe969acdd/virtiofs.sock,id=fs" "-v", kill_on_drop: false }
[2023-06-16T01:00:37.853301Z DEBUG vmm_sandboxer::utils] virtiofsd: [2023-06-16T01:00:37Z INFO  virtiofsd] Waiting for vhost-user socket connection...
[2023-06-16T01:00:37.872178Z DEBUG vmm_sandboxer::utils] virtiofsd: [2023-06-16T01:00:37Z INFO  virtiofsd] Client connected, servicing requests
[2023-06-16T01:00:37.872669Z DEBUG vmm_sandboxer::utils] cloud-hypervisor: cloud-hypervisor: 1.320936ms: <vmm> INFO:vmm/src/lib.rs:1858 -- API request event:
VmCreate(Mutex { data: VmConfig { cpus: CpusConfig { boot_vcpus: 1, max_vcpus: 1, topology: None, kvm_hyperv: false, max_phys_bits: 46, affinity: None, featur
es: CpuFeatures { amx: false } }, memory: MemoryConfig { size: 1073741824, mergeable: false, hotplug_method: Acpi, hotplug_size: None, hotplugged_size: None,
shared: true, hugepages: false, hugepage_size: None, prefault: false, zones: None, thp: true }, payload: Some(PayloadConfig { firmware: None, kernel: Some("/v
ar/lib/kuasar/vmlinux.bin"), cmdline: Some("console=hvc0 root=/dev/pmem0p1 rootflags=data=ordered,errors=remount-ro ro rootfstype=ext4 task.sharefs_type=virti
ofs  task.log_level=debug"), initramfs: None }), disks: None, net: None, rng: RngConfig { src: "/dev/urandom", iommu: false }, balloon: None, fs: Some([FsConf
ig { tag: "kuasar", socket: "/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/virtiofs.sock", num_queues: 1, queue_size: 1024,
 id: Some("fs"), pci_segment: 0 }]), pmem: Some([PmemConfig { file: "/var/lib/kuasar/kuasar.img", size: None, iommu: false, discard_writes: true, id: Some("ro
otfs"), pci_segment: 0 }]), serial: ConsoleConfig { file: None, mode: Null, iommu: false }, console: ConsoleConfig { file: Some("/tmp/9115cd3cf5d02518994f1e8a
f0c5cbe61e07c53b1c7fee69dfd33effe969acdd-task.log"), mode: File, iommu: false }, devices: None, user_devices: None, vdpa: None, vsock: Some(VsockConfig { cid:
 3, socket: "/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/task.vsock", iommu: false, id: Some("vsock"), pci_segment: 0 }),
 iommu: false, sgx_epc: None, numa: None, watchdog: false, platform: None, tpm: None, preserved_fds: None }, poisoned: false, .. }, Sender { .. })
[2023-06-16T01:00:37.872713Z DEBUG vmm_sandboxer::utils] cloud-hypervisor: cloud-hypervisor: 1.541828ms: <vmm> INFO:vmm/src/lib.rs:1858 -- API request event:
VmBoot(Sender { .. })

...

[2023-06-16T01:00:53.312823Z INFO  containerd_sandbox::rpc] append a container ContainerData { id: "ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20
...

[2023-06-16T01:00:53.313219Z DEBUG vmm_sandboxer::storage] attach storage for mount Mount { destination: "", type: "overlay", source: "overlay", options: ["index=off", "workdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/15/work", "upperdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/15/fs", "lowerdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/14/fs"] } with id storage1
[2023-06-16T01:00:53.314061Z DEBUG vmm_sandboxer::storage] overlay mount storage for Mount { destination: "", type: "overlay", source: "overlay", options: ["index=off", "workdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/15/work", "upperdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/15/fs", "lowerdir=/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs/snapshots/14/fs"] }, dest: /run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/storage1
[2023-06-16T01:00:55.311403Z DEBUG h2::codec::framed_read] received frame=Reset { stream_id: StreamId(57), error_code: CANCEL }
>>> no more output

containerd：（I added some debug log in container create path）:

time="2023-06-16T09:00:53.310418772+08:00" level=info msg="CreateContainer within sandbox I
...

time="2023-06-16T09:00:53.311098015+08:00" level=info msg="container \"ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845\": runtime handler: vmm"
time="2023-06-16T09:00:53.311119792+08:00" level=info msg="container \"ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845\": oci runtime: {io.containerd.kuasar.v1   [] []  map[] false false   0  vmm hvsock}"

time="2023-06-16T09:00:53.311135256+08:00" level=info msg="container \"ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845\": taskOpts: []"
time="2023-06-16T09:00:53.311171785+08:00" level=debug msg="Start writing stream \"stdout\" to log file \"/tmp/ubuntu.log\""
time="2023-06-16T09:00:53.311185065+08:00" level=debug msg="Start writing stream \"stderr\" to log file \"/tmp/ubuntu.log\""
time="2023-06-16T09:00:53.332690726+08:00" level=debug msg="garbage collected" d="892.277µs"

time="2023-06-16T09:00:55.313083545+08:00" level=error msg="StartContainer for \"ccf4f09edade95a37a762b30d8ac3e4f62784092038346deb98bbf2e20248845\" failed" error="rpc error: code = DeadlineExceeded desc = failed to create containerd task: context deadline exceeded"

What did you expect to happen?

examples/run_example_container.sh vmm

vmm examples works, container task gets running!

How can we reproduce it (as minimally and precisely as possible)?

follow: https://github.com/kuasar-io/kuasar#quick-start

Anything else we need to know?

No response

Dev environment

No response

renzhengeek commented 1 year ago

Is there a way to login guest to debug?

I tried this: /usr/local/bin/socat - VSOCK-CONNECT:3:1025

but got:

2023/06/16 09:23:44 socat[235757] E connect(5, AF=40 cid:3 port:1025, 16): No such device

I'm sure the cloud-hypervisor is running with vsock device cid 3.

/usr/local/bin/cloud-hypervisor --api-socket /run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/api.sock --cpus boot=1,affinity=,features= --memory size=1073741824,shared=on,hugepages=off --kernel /var/lib/kuasar/vmlinux.bin --cmdline console=hvc0 root=/dev/pmem0p1 rootflags=data=ordered,errors=remount-ro ro rootfstype=ext4 task.sharefs_type=virtiofs  task.log_level=debug --pmem id=rootfs,file=/var/lib/kuasar/kuasar.img,discard_writes=on --rng src=/dev/urandom --vsock cid=3,socket=/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/task.vsock,id=vsock --console file=/tmp/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd-task.log --fs tag=kuasar,socket=/run/kuasar-vmm/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd/virtiofs.sock,id=fs -v

seems vmm-task is running:

grep -i task /tmp/9115cd3cf5d02518994f1e8af0c5cbe61e07c53b1c7fee69dfd33effe969acdd-task.log
[    0.090767] registered taskstats version 1
[2023-06-16T01:00:38.032382Z INFO  vmm_task] Task server start with config: TaskConfig { sharefs_type: "virtiofs", log_level: "debug" }
[2023-06-16T01:00:38.032490Z DEBUG vmm_task] listen vsock port 1025 for debug console
[2023-06-16T01:00:38.032570Z DEBUG vmm_task::device] no scsi driver installed
[2023-06-16T01:00:38.034318Z INFO  vmm_task] Task server successfully started, waiting for exit signal...
...
renzhengeek commented 1 year ago

BTW, the slack link in contact section of readme page, seems not pointing to a kuasar room. Can we add slack service address in README?

Burning1020 commented 1 year ago

@renzhengeek Thaks for report. I believe after #27 merged, this bug can be fixed.

If cloud hypervisor is used as underlay vmm, you should connect the unix socket that CLH has listened, see: https://github.com/cloud-hypervisor/cloud-hypervisor/blob/main/docs/vsock.md#connecting-from-host-to-guest

I will check the slack link, thank you.

renzhengeek commented 1 year ago

Hi @Burning1020 ,

@renzhengeek Thaks for report. I believe after #27 merged, this bug can be fixed.

It works! thansk for the quick fix. 👍

If cloud hypervisor is used as underlay vmm, you should connect the unix socket that CLH has listened, see: https://github.com/cloud-hypervisor/cloud-hypervisor/blob/main/docs/vsock.md#connecting-from-host-to-guest

Thanks for the pointer~