[Kube-up][scale-out]2x2 has 9 pods stuck in ContainerCreating

[Sindica]

Start up env variables:

export KUBEMARK_NUM_NODES=100
export NUM_NODES=2
export SCALEOUT_TP_COUNT=2
export SCALEOUT_RP_COUNT=2
export RUN_PREFIX=ying-scaleout

export MASTER_DISK_SIZE=200GB
export MASTER_ROOT_DISK_SIZE=200GB
export KUBE_GCE_ZONE=us-central1-b 
export MASTER_SIZE=n1-highmem-32 
export NODE_SIZE=n1-highmem-16 
export NODE_DISK_SIZE=200GB 
export GOPATH=$HOME/go 
export KUBE_GCE_ENABLE_IP_ALIASES=true 
export KUBE_GCE_PRIVATE_CLUSTER=true 
export CREATE_CUSTOM_NETWORK=true KUBE_GCE_INSTANCE_PREFIX=${RUN_PREFIX} KUBE_GCE_NETWORK=${RUN_PREFIX} ENABLE_KCM_LEADER_ELECT=false ENABLE_SCHEDULER_LEADER_ELECT=false ETCD_QUOTA_BACKEND_BYTES=8589934592 SHARE_PARTITIONSERVER=false LOGROTATE_FILES_MAX_COUNT=50 LOGROTATE_MAX_SIZE=200M KUBE_ENABLE_APISERVER_INSECURE_PORT=true KUBE_ENABLE_PROMETHEUS_DEBUG=true KUBE_ENABLE_PPROF_DEBUG=true
export TEST_CLUSTER_LOG_LEVEL=--v=4 HOLLOW_KUBELET_TEST_LOG_LEVEL=--v=4 
#export SCALEOUT_CLUSTER=false # current need to set false in admin cluster, true in kubemark cluster
export SCALEOUT_CLUSTER=true # set to true for scaleout in admin cluster
export KUBE_FEATURE_GATES=ExperimentalCriticalPodAnnotation=true,QPSDoubleGCController=true

export NETWORK_PROVIDER=mizar

9 pods on TP1 and TP2 stuck in ContainerCreating. Endpoints were not filled in:

sindica2000@ying-dev1:~/go/src/sindica-arktos$ ./cluster/kubectl.sh --kubeconfig cluster/kubeconfig.tp-1 get pods -AT -o wide | grep -v Running
TENANT   NAMESPACE     NAME                                                  HASHKEY               READY   STATUS              RESTARTS   AGE     IP          NODE                                   NOMINATED NODE   READINESS GATES
system   kube-system   coredns-75c65c444f-pqhgk                              1658232599450222201   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-v8xz   <none>           <none>
system   kube-system   coredns-default-ying-scaleout-tp-1-7545f94d7c-nk94n   8867929730970973192   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-1-minion-group-53gw   <none>           <none>
system   kube-system   event-exporter-v0.2.5-868dff6494-xbzbr                8128911225219328752   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-kdgk   <none>           <none>
system   kube-system   fluentd-gcp-scaler-74b46b8776-9tpq6                   1573397321963459015   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-kdgk   <none>           <none>
system   kube-system   heapster-v1.6.0-beta.1-7c546f8546-8nsjm               9192474335156790251   0/2     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-1-minion-group-53gw   <none>           <none>
system   kube-system   kube-dns-autoscaler-748b78969c-bshv6                  6404757957340696799   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-v8xz   <none>           <none>
system   kube-system   kubernetes-dashboard-848965699-nz8p8                  5922915038358398901   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-v8xz   <none>           <none>
system   kube-system   l7-default-backend-6497bc5bf6-vmjs9                   6558524544689454809   0/1     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-v8xz   <none>           <none>
system   kube-system   metrics-server-v0.3.3-5f994fcb77-wjlhx                6543689972059297404   0/2     ContainerCreating   0          3h56m   <none>      ying-scaleout-rp-2-minion-group-v8xz   <none>           <none>

sindica2000@ying-dev1:~/go/src/sindica-arktos$ ./cluster/kubectl.sh --kubeconfig cluster/kubeconfig.tp-1 get ep -AT
TENANT   NAMESPACE     NAME                   ENDPOINTS       AGE     SERVICEGROUPID
system   default       kubernetes             10.40.0.2:443   3h57m   0
system   kube-system   default-http-backend   <none>          3h57m   <none>
system   kube-system   heapster               <none>          3h57m   <none>
system   kube-system   kube-dns-default       <none>          3h57m   <none>
system   kube-system   kubernetes-dashboard   <none>          3h57m   <none>
system   kube-system   metrics-server         <none>          3h57m   <none>

Branch: POC
Last commit: 2b6855f

[sonyafenge]

After delete and restart all these pods, pods change status to CrashLoopBackOff or running with same errors with:#1359

{"log":"E0215 00:46:13.127195       1 reflector.go:134] github.com/coredns/coredns/plugin/kubernetes/controller.go:315: Failed to list *v1.Service: Get https://10.0.0.1:443/api/v1/services?limit=500\u0026resourceVersion=0: dial tcp 10.0.0.1:443: connect: no route to host\n","stream":"stdout","time":"2022-02-15T00:46:13.127455344Z"}

[h-w-chen]

these pods stuck in "ContainerCreating" seems caused by mizar cni problem.
kubelet has following error message:

E0215 17:52:40.701010    6389 pod_workers.go:196] Error syncing pod 779f2040-ade0-4139-b9fa-ba
621e1e0a83 ("metrics-server-v0.3.3-5f994fcb77-rmg8n_kube-system_system(779f2040-ade0-4139-b9fa-ba621e1e0a83)"), skipping: failed to "CreatePodSandbox" for "metrics-
server-v0.3.3-5f994fcb77-rmg8n_kube-system_system(779f2040-ade0-4139-b9fa-ba621e1e0a83)" with CreatePodSandboxError: "CreatePodSandbox for pod \"metrics-server-v0.3
.3-5f994fcb77-rmg8n_kube-system_system(779f2040-ade0-4139-b9fa-ba621e1e0a83)\" failed: rpc error: code = Unknown desc = failed to set up sandbox container \"3e542be
804b8a8fd4a314d65648a0ef0f3fd8a972e6964ededf32d5865b86409\" network for pod \"metrics-server-v0.3.3-5f994fcb77-rmg8n\": NetworkPlugin cni failed to set up pod \"met
rics-server-v0.3.3-5f994fcb77-rmg8n_kube-system_system\" network: netplugin failed but error parsing its diagnostic message \"{\\n    \\\"dns\\\": {}\\n}{\\n    \\\
"code\\\": 999,\\n    \\\"msg\\\": \\\"rpc error: code = Unknown desc = Exception calling application: ConsumeInterfaces: Interface not found for pod 'metrics-serve
r-v0.3.3-5f994fcb77-rmg8n-kube-system-system'\\\"\\n}\": invalid character '{' after top-level value"

[vinaykul]

This may be an issue in Arktos sending spurious ADD for a pod which has already received a success response from CNI for the ADD call. From Mizar CNI logs:

...
I0218 23:23:14.196575   14395 mizarcni.go:56] CNI_ADD: >>>> args: '&{ContainerID:9ce7350fa172ab4f3258fc1833af2da292448cb741740cdb340814912a61090a Netns:/proc/14040/ns/net IfName:eth0 Args:IgnoreUnknown=1;K8S_POD_TENANT=system;K8S_POD_NAMESPACE=kube-system;K8S_POD_NAME=coredns-75c65c444f-ngsgn;K8S_POD_INFRA_CONTAINER_ID=9ce7350fa172ab4f3258fc1833af2da292448cb741740cdb340814912a61090a Path:/opt/cni/bin StdinData:[123 34 99 110 105 86 101 114 115 105 111 110 34 58 34 48 46 51 46 49 34 44 34 110 97 109 101 34 58 34 109 105 122 97 114 99 110 105 34 44 34 116 121 112 101 34 58 34 109 105 122 97 114 99 110 105 34 125]}'
...
...
I0218 23:23:59.359346   14395 mizarcni.go:60] CNI_ADD: Tracelog: 'CNI_ADD: Args: '{"Command":"ADD","ContainerID":"9ce7350fa172ab4f3258fc1833af2da292448cb741740cdb340814912a61090a","NetNS":"/var/run/netns/_proc_14040_ns_net","IfName":"eth0","CniPath":"/opt/cni/bin","K8sPodNamespace":"kube-system","K8sPodName":"coredns-75c65c444f-ngsgn","K8sPodTenant":"system","CniVersion":"0.3.1","NetworkName":"mizarcni","Plugin":"mizarcni"}'
CNI_ADD: Activating interface: 'interface_id:{pod_id:{k8s_pod_name:"coredns-75c65c444f-ngsgn"  k8s_namespace:"kube-system"  k8s_pod_tenant:"system"}  interface:"ens4"}  veth:{name:"eth-139276c9"  peer:"veth-139276c9"}  address:{version:"4"  ip_address:"243.104.0.13"  ip_prefix:"16"  gateway_ip:"243.104.0.1"  mac:"e2:aa:73:24:53:9b"  tunnel_id:"2874758"}  droplet:{version:"4"  ip_address:"10.40.0.3"  mac:"42:01:0a:28:00:03"}  bouncers:{version:"4"  ip_address:"10.40.0.3"  mac:"42:01:0a:28:00:03"}  status:consumed  pod_label_value:"9"  namespace_label_value:"0"  egress_bandwidth_bytes_per_sec:"0"  pod_network_priority:"High"  pod_network_class:"Premium"  subnet_ip:"243.104.0.0"  subnet_prefix:"16"'
CNI_ADD: Activate interface result: '[Move interface 'eth-139276c9/25' to netns '_proc_14040_ns_net'] + [Rename interface 'eth-139276c9' to 'eth0'] + [Retrieve loopback interface] + [Set loopback interface UP] + [Set interface 'eth0' UP] + [Set ip addr '243.104.0.13' on interface 'eth0'] + [Set gateway '243.104.0.1' for interface 'eth0'] + [Disable tso on interface 'eth0'] + [Cmd: '/usr/sbin/ip netns exec _proc_14040_ns_net ethtool -K eth0 tso off gso off ufo off -> Result: 'Cannot change udp-fragmentation-offload
'] + [Cmd: '/usr/sbin/ip netns exec _proc_14040_ns_net ethtool --offload eth0 rx off tx off' -> Result: '']'
'
I0218 23:23:59.359365   14395 mizarcni.go:65] CNI_ADD: Success - interface added for pod 'kube-system/coredns-75c65c444f-ngsgn'
I0218 23:23:59.359374   14395 mizarcni.go:68] CNI_ADD: <<<<                      <-------- CNI ADD was successful.
...
...

I0218 23:23:59.375173   16788 mizarcni.go:56] CNI_ADD: >>>> args: '&{ContainerID:0a42af1f180f257af2e7630bd43f25a4ffd36fc829f58e67973378e59fbd5ddd Netns:/proc/15881/ns/net IfName:eth0 Args:IgnoreUnknown=1;K8S_POD_TENANT=system;K8S_POD_NAMESPACE=kube-system;K8S_POD_NAME=coredns-75c65c444f-ngsgn;K8S_POD_INFRA_CONTAINER_ID=0a42af1f180f257af2e7630bd43f25a4ffd36fc829f58e67973378e59fbd5ddd Path:/opt/cni/bin StdinData:[123 34 99 110 105 86 101 114 115 105 111 110 34 58 34 48 46 51 46 49 34 44 34 110 97 109 101 34 58 34 109 105 122 97 114 99 110 105 34 44 34 116 121 112 101 34 58 34 109 105 122 97 114 99 110 105 34 125]}'
I0218 23:24:04.384106   16788 mizarcni.go:60] CNI_ADD: Tracelog: 'CNI_ADD: Args: '{"Command":"ADD","ContainerID":"0a42af1f180f257af2e7630bd43f25a4ffd36fc829f58e67973378e59fbd5ddd","NetNS":"/var/run/netns/_proc_15881_ns_net","IfName":"eth0","CniPath":"/opt/cni/bin","K8sPodNamespace":"kube-system","K8sPodName":"coredns-75c65c444f-ngsgn","K8sPodTenant":"system","CniVersion":"0.3.1","NetworkName":"mizarcni","Plugin":"mizarcni"}'
'
E0218 23:24:04.384128   16788 mizarcni.go:63] CNI_ADD: Error: 'rpc error: code = Unknown desc = Exception calling application: ConsumeInterfaces: Interface not found for pod 'coredns-75c65c444f-ngsgn-kube-system-system''
I0218 23:24:04.384175   16788 mizarcni.go:68] CNI_ADD: <<<<                <--------- Kubelet calls CNI ADD for same pod with a new container ID for infra container even though we succeeded the first ADD.
...
...

This behavior is not seen with upstream.

[h-w-chen]

with latest mizar:dev image, plus a simple fix of mizar installation script (which does not install mizar binary as preliminary step; PR is on the way), this issue is almost gone in kube-up scale-out cluster.