Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

support gVisor in minikube=>cri-o with podman #2219

Closed
gattytto opened this issue Mar 21, 2020 · 4 comments
Closed

support gVisor in minikube=>cri-o with podman #2219

gattytto opened this issue Mar 21, 2020 · 4 comments

Comments

@gattytto
Copy link

gattytto commented Mar 21, 2020 •
edited
Loading

Hello

I am using minikube (with vm-driver=none) inside a LXC container and now I have decided to uninstall docker and install cri-o and podman instead.

cri-o now works with kata and runc just fine.

but adding the runsc runtime is not working right away.

[crio.runtime.runtimes.runc]
runtime_path = ""
runtime_type = "oci"
runtime_root = "/run/runc"

# Kata Containers is an OCI runtime, where containers are run inside lightweight
[crio.runtime.runtimes.kata]
runtime_path = "/snap/kata-containers/current/usr/bin/kata-runtime"
runtime_type = "oci"

[crio.runtime.runtimes.runsc]
runtime_path = "/usr/local/bin/runsc"

I have asked crio issue cri-o/cri-o#1991 to be reopened around sending arguments to the runtime binary. Before that happens (that they add runtime_args) it would be good to have gVisor check a default location for a configuration file (like /etc/default/gVisor) so I can set debug levels and try to see some runtime info.

trying this pod:

apiVersion: v1
kind: Pod
metadata:
  name: gvisor-crio
  labels:
    run: gvisor-crio
spec:
  runtimeClassName: runsc
  containers:
    - name: gvisor-crio
      image: ubuntu
      command: ["/bin/bash", "-ec", "while :; do echo '.'; sleep 5 ; done"]
  dnsPolicy: ClusterFirst
  restartPolicy: Never

kubectl get events -Aw:

default     0s          Normal    Scheduled       pod/gvisor-crio                         Successfully assigned default/gvisor-crio to hfocal
default     0s          Normal    Pulling         pod/gvisor-crio                         Pulling image "ubuntu"
default     0s          Normal    Pulled          pod/gvisor-crio                         Successfully pulled image "ubuntu"
default     0s          Normal    Created         pod/gvisor-crio                         Created container gvisor-crio
default     0s          Normal    Started         pod/gvisor-crio                         Started container gvisor-crio

crictl pods:

POD ID              CREATED             STATE               NAME                                           NAMESPACE           ATTEMPT
fc12dcdeb0d0d       2 minutes ago       NotReady            gvisor-crio                                    default             0

crictl inspectp -o yaml fc12dcdeb0d0d :

status:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"v1","kind":"Pod","metadata":{"annotations":{},"labels":{"run":"gvisor-crio"},"name":"gvisor-crio","namespace":"default"},"spec":{"containers":[{"command":["/bin/bash","-ec","while :; do echo '.'; sleep 5 ; done"],"image":"ubuntu","name":"gvisor-crio"}],"dnsPolicy":"ClusterFirst","restartPolicy":"Never","runtimeClassName":"runsc"}}
    kubernetes.io/config.seen: "2020-03-21T02:09:14.066018706-03:00"
    kubernetes.io/config.source: api
  createdAt: "2020-03-21T02:09:14.401408601-03:00"
  id: fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03
  labels:
    io.kubernetes.container.name: POD
    io.kubernetes.pod.name: gvisor-crio
    io.kubernetes.pod.namespace: default
    io.kubernetes.pod.uid: 5a0a2ade-8fb0-4a19-9b1c-247d41dea277
    run: gvisor-crio
  linux:
    namespaces:
      options:
        ipc: POD
        network: POD
        pid: CONTAINER
  metadata:
    attempt: 0
    name: gvisor-crio
    namespace: default
    uid: 5a0a2ade-8fb0-4a19-9b1c-247d41dea277
  network:
    additionalIps:
    - ip: 1100:200::4b
    ip: 10.88.0.75
  runtimeHandler: ""
  state: SANDBOX_NOTREADY

and finally journalctl -f:

Mar 21 02:09:14 hfocal kubelet[4482]: I0321 02:09:14.162366    4482 reconciler.go:209] operationExecutor.VerifyControllerAttachedVolume started for volume "default-token-v2xzb" (UniqueName: "kubernetes.io/secret/5a0a2ade-8fb0-4a19-9b1c-247d41dea277-default-token-v2xzb") pod "gvisor-crio" (UID: "5a0a2ade-8fb0-4a19-9b1c-247d41dea277")
Mar 21 02:09:14 hfocal systemd[1]: Started Kubernetes transient mount for /var/lib/kubelet/pods/5a0a2ade-8fb0-4a19-9b1c-247d41dea277/volumes/kubernetes.io~secret/default-token-v2xzb.
Mar 21 02:09:14 hfocal systemd[1]: run-rfbda3d397eea41cf8aa017baf966dd05.scope: Succeeded.
Mar 21 02:09:14 hfocal systemd[1]: Started crio-conmon-fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03.scope.
Mar 21 02:09:14 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <ninfo>: attach sock path: /var/run/crio/fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03/attach
Mar 21 02:09:14 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/crio/fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03/attach}
Mar 21 02:09:14 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <ninfo>: terminal_ctrl_fd: 17
Mar 21 02:09:14 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <ninfo>: winsz read side: 19, winsz write side: 19
Mar 21 02:09:14 hfocal systemd-networkd[72]: veth16d66913: Link UP
Mar 21 02:09:14 hfocal systemd-udevd[125081]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Mar 21 02:09:14 hfocal networkd-dispatcher[401]: WARNING:Unknown index 45 seen, reloading interface list
Mar 21 02:09:14 hfocal systemd-udevd[125081]: Using default interface naming scheme 'v243'.
Mar 21 02:09:14 hfocal systemd-networkd[72]: veth16d66913: Gained carrier
Mar 21 02:09:14 hfocal systemd-udevd[125081]: veth16d66913: Could not generate persistent MAC: No data available
Mar 21 02:09:14 hfocal systemd-networkd[72]: veth16d66913: rtnl: received neighbor message with invalid family, ignoring.
Mar 21 02:09:14 hfocal systemd-networkd[72]: veth16d66913: rtnl: received neighbor message with invalid family, ignoring.
Mar 21 02:09:14 hfocal kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth16d66913: link becomes ready
Mar 21 02:09:14 hfocal kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Mar 21 02:09:14 hfocal kernel: cni0: port 4(veth16d66913) entered blocking state
Mar 21 02:09:14 hfocal kernel: cni0: port 4(veth16d66913) entered disabled state
Mar 21 02:09:14 hfocal kernel: device veth16d66913 entered promiscuous mode
Mar 21 02:09:14 hfocal kernel: cni0: port 4(veth16d66913) entered blocking state
Mar 21 02:09:14 hfocal kernel: cni0: port 4(veth16d66913) entered forwarding state
Mar 21 02:09:15 hfocal systemd-networkd[72]: veth16d66913: Gained IPv6LL
Mar 21 02:09:16 hfocal kernel: IPv4: martian source 10.88.0.75 from 10.88.0.75, on dev eth0
Mar 21 02:09:16 hfocal kernel: ll header: 00000000: ff ff ff ff ff ff e6 3b 01 3a ae 8f 08 06
Mar 21 02:09:19 hfocal systemd[1]: Started crio-conmon-e268cad5c813f5bb510359ceafd01034979706f243582dd229bccdf8398bb904.scope.
Mar 21 02:09:19 hfocal conmon[125208]: conmon e268cad5c813f5bb5103 <ninfo>: attach sock path: /var/run/crio/e268cad5c813f5bb510359ceafd01034979706f243582dd229bccdf8398bb904/attach
Mar 21 02:09:19 hfocal conmon[125208]: conmon e268cad5c813f5bb5103 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/crio/e268cad5c813f5bb510359ceafd01034979706f243582dd229bccdf8398bb904/attach}
Mar 21 02:09:19 hfocal conmon[125208]: conmon e268cad5c813f5bb5103 <ninfo>: terminal_ctrl_fd: 17
Mar 21 02:09:19 hfocal conmon[125208]: conmon e268cad5c813f5bb5103 <ninfo>: winsz read side: 19, winsz write side: 19
Mar 21 02:09:19 hfocal systemd[1]: crio-conmon-e268cad5c813f5bb510359ceafd01034979706f243582dd229bccdf8398bb904.scope: Succeeded.
Mar 21 02:10:26 hfocal systemd-networkd[72]: veth16d66913: Link DOWN
Mar 21 02:10:26 hfocal systemd-networkd[72]: veth16d66913: Lost carrier
Mar 21 02:10:26 hfocal kernel: cni0: port 4(veth16d66913) entered disabled state
Mar 21 02:10:26 hfocal kernel: device veth16d66913 left promiscuous mode
Mar 21 02:10:26 hfocal kernel: cni0: port 4(veth16d66913) entered disabled state
Mar 21 02:10:26 hfocal systemd-networkd[72]: rtnl: received neighbor for link '45' we don't know about, ignoring.
Mar 21 02:10:26 hfocal systemd-networkd[72]: rtnl: received neighbor for link '45' we don't know about, ignoring.
Mar 21 02:10:26 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <nwarn>: stdio_input read failed Resource temporarily unavailable
Mar 21 02:10:26 hfocal conmon[125087]: conmon fc12dcdeb0d0d9e23d58 <nwarn>: stdio_input read failed Resource temporarily unavailable
Mar 21 02:10:26 hfocal kubelet[4482]: I0321 02:10:26.595405    4482 reconciler.go:183] operationExecutor.UnmountVolume started for volume "default-token-v2xzb" (UniqueName: "kubernetes.io/secret/5a0a2ade-8fb0-4a19-9b1c-247d41dea277-default-token-v2xzb") pod "5a0a2ade-8fb0-4a19-9b1c-247d41dea277" (UID: "5a0a2ade-8fb0-4a19-9b1c-247d41dea277")
Mar 21 02:10:26 hfocal kubelet[4482]: I0321 02:10:26.596613    4482 operation_generator.go:713] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/5a0a2ade-8fb0-4a19-9b1c-247d41dea277-default-token-v2xzb" (OuterVolumeSpecName: "default-token-v2xzb") pod "5a0a2ade-8fb0-4a19-9b1c-247d41dea277" (UID: "5a0a2ade-8fb0-4a19-9b1c-247d41dea277"). InnerVolumeSpecName "default-token-v2xzb". PluginName "kubernetes.io/secret", VolumeGidValue ""
Mar 21 02:10:26 hfocal systemd[817]: var-lib-kubelet-pods-5a0a2ade\x2d8fb0\x2d4a19\x2d9b1c\x2d247d41dea277-volumes-kubernetes.io\x7esecret-default\x2dtoken\x2dv2xzb.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[491]: var-lib-kubelet-pods-5a0a2ade\x2d8fb0\x2d4a19\x2d9b1c\x2d247d41dea277-volumes-kubernetes.io\x7esecret-default\x2dtoken\x2dv2xzb.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[1]: var-lib-kubelet-pods-5a0a2ade\x2d8fb0\x2d4a19\x2d9b1c\x2d247d41dea277-volumes-kubernetes.io\x7esecret-default\x2dtoken\x2dv2xzb.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[1]: crio-conmon-fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03.scope: Succeeded.
Mar 21 02:10:26 hfocal systemd[817]: data-podman-overlay-be8440299ff98b18fbe4ad8512769309cfa38621741eef95d101c5ab5da22f13-merged.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[491]: data-podman-overlay-be8440299ff98b18fbe4ad8512769309cfa38621741eef95d101c5ab5da22f13-merged.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[1]: data-podman-overlay-be8440299ff98b18fbe4ad8512769309cfa38621741eef95d101c5ab5da22f13-merged.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[491]: run-containers-storage-overlay\x2dcontainers-fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03-userdata-shm.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[817]: run-containers-storage-overlay\x2dcontainers-fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03-userdata-shm.mount: Succeeded.
Mar 21 02:10:26 hfocal systemd[1]: run-containers-storage-overlay\x2dcontainers-fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03-userdata-shm.mount: Succeeded.
Mar 21 02:10:26 hfocal kubelet[4482]: I0321 02:10:26.695690    4482 reconciler.go:303] Volume detached for volume "default-token-v2xzb" (UniqueName: "kubernetes.io/secret/5a0a2ade-8fb0-4a19-9b1c-247d41dea277-default-token-v2xzb") on node "hfocal" DevicePath ""
Mar 21 02:10:27 hfocal kubelet[4482]: W0321 02:10:27.481919    4482 pod_container_deletor.go:75] Container "fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03" not found in pod's containers

trying to run something in the pod:

$ kubectl exec pod/gvisor-crio /bin/bash 
error: Internal error occurred: error executing command in container: container is not created or running

$ kubectl exec -it pod/gvisor-crio /bin/bash 
error: cannot exec into a container in a completed pod; current phase is Failed
$ kubectl logs pod/gvisor-crio 
[no results]

crictl inspect -o yaml $(crictl ps -lq):

pid: -1
sandboxId: fc12dcdeb0d0d9e23d584114972c07534cf6e239f21584d84a019f9abcbdbe03
status:
  annotations:
    io.kubernetes.container.hash: d03e17e9
    io.kubernetes.container.restartCount: "0"
    io.kubernetes.container.terminationMessagePath: /dev/termination-log
    io.kubernetes.container.terminationMessagePolicy: File
    io.kubernetes.pod.terminationGracePeriod: "30"
  createdAt: "2020-03-21T02:09:19.928257073-03:00"
  exitCode: -1
  finishedAt: "2020-03-21T02:09:19.958409426-03:00"
  id: e268cad5c813f5bb510359ceafd01034979706f243582dd229bccdf8398bb904
  image:
    image: docker.io/library/ubuntu:latest
  imageRef: docker.io/library/ubuntu@sha256:bec5a2727be7fff3d308193cfde3491f8fba1a2ba392b7546b43a051853a341d
  labels:
    io.kubernetes.container.name: gvisor-crio
    io.kubernetes.pod.name: gvisor-crio
    io.kubernetes.pod.namespace: default
    io.kubernetes.pod.uid: 5a0a2ade-8fb0-4a19-9b1c-247d41dea277
  logPath: /var/log/pods/default_gvisor-crio_5a0a2ade-8fb0-4a19-9b1c-247d41dea277/gvisor-crio/0.log
  message: ""
  metadata:
    attempt: 0
    name: gvisor-crio
  mounts:
  - containerPath: /etc/hosts
    hostPath: /var/lib/kubelet/pods/5a0a2ade-8fb0-4a19-9b1c-247d41dea277/etc-hosts
    propagation: PROPAGATION_PRIVATE
    readonly: false
    selinuxRelabel: false
  - containerPath: /dev/termination-log
    hostPath: /var/lib/kubelet/pods/5a0a2ade-8fb0-4a19-9b1c-247d41dea277/containers/gvisor-crio/405947e4
    propagation: PROPAGATION_PRIVATE
    readonly: false
    selinuxRelabel: false
  - containerPath: /var/run/secrets/kubernetes.io/serviceaccount
    hostPath: /var/lib/kubelet/pods/5a0a2ade-8fb0-4a19-9b1c-247d41dea277/volumes/kubernetes.io~secret/default-token-v2xzb
    propagation: PROPAGATION_PRIVATE
    readonly: true
    selinuxRelabel: false
  reason: Error
  startedAt: "2020-03-21T02:09:20.030496867-03:00"
  state: CONTAINER_EXITED
@gattytto
Copy link
Author

gattytto commented Mar 21, 2020 •
edited
Loading

oh well, after restarting crio it just worked..

kubectl get pod -A                                                                                  
NAMESPACE          NAME                                           READY   STATUS              RESTARTS   AGE
default            gvisor-crio                                    0/1     ContainerCreating   0          5s

kubectl exec -it gvisor-crio /bin/bash                                                                 
root@gvisor-crio:/# cat /etc/*release*
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=18.04
DISTRIB_CODENAME=bionic
DISTRIB_DESCRIPTION="Ubuntu 18.04.4 LTS"
NAME="Ubuntu"
VERSION="18.04.4 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.4 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
root@gvisor-crio:/# uname -a
Linux gvisor-crio 4.4.0 #1 SMP Sun Jan 10 15:06:54 PST 2016 x86_64 x86_64 x86_64 GNU/Linux

but it is not very clear to me on how cni configuration will work. should there be config details present in the pod manifest yaml?.

@gattytto
Copy link
Author

https://pastebin.com/88G62kWy here is the complete debug log after putting a wrapper script for runsc runtime.

@gattytto
Copy link
Author

and journal:

Mar 22 19:39:57 hfocal systemd[1]: Stopping Container Runtime Interface for OCI (CRI-O)...
Mar 22 19:39:57 hfocal kubelet[4482]: W0322 19:39:57.502793    4482 clientconn.go:1120] grpc: addrConn.createTransport failed to connect to {/var/run/crio/crio.sock 0  <nil>}. Err :connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory". Reconnecting...
Mar 22 19:39:57 hfocal systemd[1]: crio.service: Succeeded.
Mar 22 19:39:57 hfocal systemd[1]: Stopped Container Runtime Interface for OCI (CRI-O).
Mar 22 19:39:57 hfocal systemd[1]: Starting CRI-O Auto Update Script...
Mar 22 19:39:57 hfocal crio[300266]: major and minor version unchanged; no wipe needed
Mar 22 19:39:57 hfocal systemd[1]: crio-wipe.service: Succeeded.
Mar 22 19:39:57 hfocal systemd[1]: Started CRI-O Auto Update Script.
Mar 22 19:39:57 hfocal systemd[1]: Starting Container Runtime Interface for OCI (CRI-O)...
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.606895004-03:00" level=info msg="using conmon executable \"/usr/libexec/podman/conmon\""
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.612130741-03:00" level=info msg="Found CNI network crio-bridge (type=bridge) at /etc/cni/net.d/100-crio-bridge.conf"
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.612196664-03:00" level=info msg="Found CNI network 200-loopback.conf (type=loopback) at /etc/cni/net.d/200-loopback.conf"
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.612230821-03:00" level=warning msg="Error loading CNI config list file /etc/cni/net.d/87-podman-bridge.conflist: error parsing configuration list: invalid character '}' looking for beginning of object key string"
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.612377475-03:00" level=info msg="Found CNI network rkt.kubernetes.io (type=bridge) at /etc/cni/net.d/k8s.conf"
Mar 22 19:39:57 hfocal crio[300291]: time="2020-03-22 19:39:57.614450001-03:00" level=info msg="no seccomp profile specified, using the internal default"
Mar 22 19:39:57 hfocal kubelet[4482]: E0322 19:39:57.925761    4482 remote_runtime.go:182] ListPodSandbox with filter &PodSandboxFilter{Id:,State:&PodSandboxStateValue{State:SANDBOX_READY,},LabelSelector:map[string]string{},} from runtime service failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:57 hfocal kubelet[4482]: E0322 19:39:57.925799    4482 kuberuntime_sandbox.go:210] ListPodSandbox failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:57 hfocal kubelet[4482]: E0322 19:39:57.925805    4482 kubelet_pods.go:1055] Error listing containers: &status.statusError{Code:14, Message:"all SubConns are in TransientFailure, latest connection error: connection error: desc = \"transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory\"", Details:[]*any.Any(nil), XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}
Mar 22 19:39:57 hfocal kubelet[4482]: E0322 19:39:57.925825    4482 kubelet.go:1995] Failed cleaning pods: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.098994599-03:00" level=info msg="Got pod network &{Name:nginx-ingress-controller-65d55d6d5d-hgbz5 Namespace:kube-system ID:fbdba969a357d4fdfc8797b0f120253b0c641546350947352399b001ef1b8bab NetNS:/proc/23199/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099021529-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099168817-03:00" level=info msg="Got pod network &{Name:coredns-6955765f44-rnn8z Namespace:kube-system ID:c28f5dc97f3dd12888368d499e08e8e512f82d225ae6f41d4baf44e6d7472181 NetNS:/proc/4679/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099180876-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099250762-03:00" level=info msg="Got pod network &{Name:coredns-6955765f44-t49wz Namespace:kube-system ID:03147a6e95d4cecaf2dfc6b307dee6b48576e501cf1a9a84454ab92163441db8 NetNS:/proc/4673/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099263435-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099327453-03:00" level=info msg="Got pod network &{Name:tekton-triggers-webhook-874bdd9f4-85ntf Namespace:tekton-pipelines ID:f4868a268137694f51b1f080c8b40a1db69dd63919c09dfa53d5b03662f2ab81 NetNS:/proc/56164/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099337851-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099401430-03:00" level=info msg="Got pod network &{Name:tekton-triggers-controller-6f8fccf4b5-zwlhk Namespace:tekton-pipelines ID:83c5ff60238d3830fd5774f19821c6928e4362aa563545f8204354b7ae2269f6 NetNS:/proc/56156/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099412017-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099473482-03:00" level=info msg="Got pod network &{Name:tekton-pipelines-webhook-5d8c754ccd-p4ncb Namespace:tekton-pipelines ID:c48fc7fc5329d8750856a4f0e586a14d0410d6a9ac73edd7de10d2a3dd3b106b NetNS:/proc/46307/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099486099-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099547708-03:00" level=info msg="Got pod network &{Name:tekton-pipelines-controller-567745f574-mzsvn Namespace:tekton-pipelines ID:8b46fe52a68fbda4a0a3818dd67e089bb57d3362ca2953f5670c54c4af4e0858 NetNS:/proc/46278/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:39:58 hfocal crio[300291]: time="2020-03-22 19:39:58.099558011-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:39:58 hfocal systemd[1]: Started Container Runtime Interface for OCI (CRI-O).
Mar 22 19:39:58 hfocal kubelet[4482]: E0322 19:39:58.183099    4482 remote_runtime.go:182] ListPodSandbox with filter nil from runtime service failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:58 hfocal kubelet[4482]: E0322 19:39:58.183131    4482 kuberuntime_sandbox.go:210] ListPodSandbox failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:58 hfocal kubelet[4482]: E0322 19:39:58.183140    4482 generic.go:205] GenericPLEG: Unable to retrieve pods: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:58 hfocal kubelet[4482]: E0322 19:39:58.397514    4482 remote_runtime.go:81] Version from runtime service failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:39:58 hfocal kubelet[4482]: E0322 19:39:58.397537    4482 kuberuntime_manager.go:281] Get remote runtime version failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: no such file or directory"
Mar 22 19:40:07 hfocal kubelet[4482]: I0322 19:40:07.868834    4482 reconciler.go:209] operationExecutor.VerifyControllerAttachedVolume started for volume "default-token-v2xzb" (UniqueName: "kubernetes.io/secret/ddfd3a9e-bebd-4b15-a1dd-a643fd88eb47-default-token-v2xzb") pod "gvisor-crio" (UID: "ddfd3a9e-bebd-4b15-a1dd-a643fd88eb47")
Mar 22 19:40:07 hfocal systemd[1]: Started Kubernetes transient mount for /var/lib/kubelet/pods/ddfd3a9e-bebd-4b15-a1dd-a643fd88eb47/volumes/kubernetes.io~secret/default-token-v2xzb.
Mar 22 19:40:07 hfocal systemd[1]: run-r9aeadfa6568340c6bad772ac19d82f58.scope: Succeeded.
Mar 22 19:40:08 hfocal crio[300291]: time="2020-03-22 19:40:08.133200822-03:00" level=info msg="attempting to run pod sandbox with infra container: default/gvisor-crio/POD" id=b70202a4-d022-470a-8b08-878d4378a82f
Mar 22 19:40:08 hfocal systemd[1]: Started crio-conmon-40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc.scope.
Mar 22 19:40:08 hfocal conmon[301265]: conmon 40cf9453741c82075970 <ninfo>: attach sock path: /var/run/crio/40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc/attach
Mar 22 19:40:08 hfocal conmon[301265]: conmon 40cf9453741c82075970 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/crio/40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc/attach}
Mar 22 19:40:08 hfocal conmon[301265]: conmon 40cf9453741c82075970 <ninfo>: terminal_ctrl_fd: 23
Mar 22 19:40:08 hfocal conmon[301265]: conmon 40cf9453741c82075970 <ninfo>: winsz read side: 25, winsz write side: 25
Mar 22 19:40:08 hfocal crio[300291]: time="2020-03-22 19:40:08.257680518-03:00" level=info msg="Got pod network &{Name:gvisor-crio Namespace:default ID:40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc NetNS:/proc/301284/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:40:08 hfocal crio[300291]: time="2020-03-22 19:40:08.257704975-03:00" level=info msg="About to add CNI network cni-loopback (type=loopback)"
Mar 22 19:40:08 hfocal crio[300291]: time="2020-03-22 19:40:08.259434855-03:00" level=info msg="Got pod network &{Name:gvisor-crio Namespace:default ID:40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc NetNS:/proc/301284/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:40:08 hfocal crio[300291]: time="2020-03-22 19:40:08.259454792-03:00" level=info msg="About to add CNI network crio-bridge (type=bridge)"
Mar 22 19:40:08 hfocal systemd-networkd[72]: veth32794318: Link UP
Mar 22 19:40:08 hfocal systemd-udevd[301259]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Mar 22 19:40:08 hfocal networkd-dispatcher[401]: WARNING:Unknown index 66 seen, reloading interface list
Mar 22 19:40:08 hfocal systemd-networkd[72]: veth32794318: Gained carrier
Mar 22 19:40:08 hfocal systemd-udevd[301259]: Using default interface naming scheme 'v243'.
Mar 22 19:40:08 hfocal systemd-udevd[301259]: veth32794318: Could not generate persistent MAC: No data available
Mar 22 19:40:08 hfocal systemd-networkd[72]: veth32794318: rtnl: received neighbor message with invalid family, ignoring.
Mar 22 19:40:08 hfocal systemd-networkd[72]: veth32794318: rtnl: received neighbor message with invalid family, ignoring.
Mar 22 19:40:08 hfocal kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth32794318: link becomes ready
Mar 22 19:40:08 hfocal kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Mar 22 19:40:08 hfocal kernel: cni0: port 4(veth32794318) entered blocking state
Mar 22 19:40:08 hfocal kernel: cni0: port 4(veth32794318) entered disabled state
Mar 22 19:40:08 hfocal kernel: device veth32794318 entered promiscuous mode
Mar 22 19:40:08 hfocal kernel: cni0: port 4(veth32794318) entered blocking state
Mar 22 19:40:08 hfocal kernel: cni0: port 4(veth32794318) entered forwarding state
Mar 22 19:40:10 hfocal systemd-networkd[72]: veth32794318: Gained IPv6LL
Mar 22 19:40:10 hfocal kernel: IPv4: martian source 10.88.0.96 from 10.88.0.96, on dev eth0
Mar 22 19:40:10 hfocal kernel: ll header: 00000000: ff ff ff ff ff ff 72 e1 2e ad 70 4f 08 06
Mar 22 19:40:10 hfocal crio[300291]: time="2020-03-22 19:40:10.392928530-03:00" level=info msg="Got pod network &{Name:gvisor-crio Namespace:default ID:40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc NetNS:/proc/301284/ns/net Networks:[] RuntimeConfig:map[crio-bridge:{IP: PortMappings:[] Bandwidth:<nil> IpRanges:[]}]}"
Mar 22 19:40:10 hfocal crio[300291]: time="2020-03-22 19:40:10.392953491-03:00" level=info msg="About to check CNI network crio-bridge (type=bridge)"
Mar 22 19:40:10 hfocal crio[300291]: time="2020-03-22 19:40:10.393176230-03:00" level=info msg="ran pod sandbox 40cf9453741c8207597032bac076cb5c49e0d4ff496fae3289e816d81beadadc with infra container: default/gvisor-crio/POD" id=b70202a4-d022-470a-8b08-878d4378a82f
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.299484097-03:00" level=info msg="Attempting to create container: default/gvisor-crio/gvisor-crio" id=03a7e6a2-5f4a-483b-82ec-4ddb344c03b5
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.322822357-03:00" level=warning msg="requested logPath for ctr id 208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f is a relative path: gvisor-crio/0.log" id=03a7e6a2-5f4a-483b-82ec-4ddb344c03b5
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.322846993-03:00" level=warning msg="logPath from relative path is now absolute: /var/log/pods/default_gvisor-crio_ddfd3a9e-bebd-4b15-a1dd-a643fd88eb47/gvisor-crio/0.log" id=03a7e6a2-5f4a-483b-82ec-4ddb344c03b5
Mar 22 19:40:13 hfocal systemd[1]: Started crio-conmon-208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f.scope.
Mar 22 19:40:13 hfocal conmon[301398]: conmon 208423bc85121eba087d <ninfo>: attach sock path: /var/run/crio/208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f/attach
Mar 22 19:40:13 hfocal conmon[301398]: conmon 208423bc85121eba087d <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/crio/208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f/attach}
Mar 22 19:40:13 hfocal conmon[301398]: conmon 208423bc85121eba087d <ninfo>: terminal_ctrl_fd: 23
Mar 22 19:40:13 hfocal conmon[301398]: conmon 208423bc85121eba087d <ninfo>: winsz read side: 25, winsz write side: 25
Mar 22 19:40:13 hfocal systemd[1]: crio-conmon-208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f.scope: Succeeded.
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.374518232-03:00" level=error msg="insufficient ps information; pid likely stopped" id=03a7e6a2-5f4a-483b-82ec-4ddb344c03b5
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.374544355-03:00" level=info msg="Created container 208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f: default/gvisor-crio/gvisor-crio" id=03a7e6a2-5f4a-483b-82ec-4ddb344c03b5
Mar 22 19:40:13 hfocal crio[300291]: time="2020-03-22 19:40:13.457852470-03:00" level=info msg="Started container 208423bc85121eba087d4f8c5847fadcbbefb7f5861d447f7bcd6ce30810474f: default/gvisor-crio/gvisor-crio" id=9b80954e-ff93-4a8e-90b9-727c7839e6d3

@gattytto
Copy link
Author

gattytto commented Mar 23, 2020 •
edited
Loading

for the record, setting:

# manage_ns_lifecycle determines whether we pin and remove namespaces
# and manage their lifecycle
manage_ns_lifecycle = false

to true in the crio.conf file fixed this

@h4n0sh1 h4n0sh1 mentioned this issue Jan 23, 2021
Closed
@cristicalin cristicalin mentioned this issue May 30, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@gattytto