calico: Calico tries to reassign IP addresses already in use
Calico tries to reassign IP addresses already in use
Expected Behavior
Calico should assign a unused IP address to a new created pod
Current Behavior
Calico trise several IP addresses, already in use by other pods, leading to multiple errors like
Failed to create pod sandbox: rpc error: code = Unknown desc = failed to set up sandbox container "9f90580e9dd409a5ab621ef44c1637972ec6fb5d55db732c1943647ce1cf9e00" network for pod "nginx-ingress-controller-6664bc7855-8hxwv": networkPlugin cni failed to set up pod "nginx-ingress-controller-6664bc7855-8hxwv_eai-selfservice-dev" network: error adding host side routes for interface: calicfa03c2c5b1, error: route (Ifindex: 436, Dst: 100.80.1.62/32, Scope: 253) already exists for an interface other than 'calicfa03c2c5b1'
with changing IP addresses. At some point the container starts with a free IP address assigned.
Steps to Reproduce (for bugs)
I’m not sure on how to reproduce this, but I’ll provide as many informations as I can: The events on a pods looks like this:
Warning FailedCreatePodSandBox 43s kubelet, k8s-worker-01.example.com Failed to create pod sandbox: rpc error: code = Unknown desc = failed to set up sandbox container "9f90580e9dd409a5ab621ef44c1637972ec6fb5d55db732c1943647ce1cf9e00" network for pod "nginx-ingress-controller-6664bc7855-8hxwv": networkPlugin cni failed to set up pod "nginx-ingress-controller-6664bc7855-8hxwv_eai-selfservice-dev" network: error adding host side routes for interface: calicfa03c2c5b1, error: route (Ifindex: 436, Dst: 100.80.1.62/32, Scope: 253) already exists for an interface other than 'calicfa03c2c5b1'
Warning FailedCreatePodSandBox 37s kubelet, k8s-worker-01.example.com Failed to create pod sandbox: rpc error: code = Unknown desc = failed to set up sandbox container "b9ecd16415de567bdad4523f42ee9e0a1b7ebf609eed03a61e88f117b2b5f2d1" network for pod "nginx-ingress-controller-6664bc7855-8hxwv": networkPlugin cni failed to set up pod "nginx-ingress-controller-6664bc7855-8hxwv_eai-selfservice-dev" network: error adding host side routes for interface: calicfa03c2c5b1, error: route (Ifindex: 437, Dst: 100.80.1.63/32, Scope: 253) already exists for an interface other than 'calicfa03c2c5b1'
Warning FailedCreatePodSandBox 26s kubelet, k8s-worker-01.example.com Failed to create pod sandbox: rpc error: code = Unknown desc = failed to set up sandbox container "667a2b553cf6598f7fc0da75dfb9d5bd18163c87348db3a03e42be98d9a0762c" network for pod "nginx-ingress-controller-6664bc7855-8hxwv": networkPlugin cni failed to set up pod "nginx-ingress-controller-6664bc7855-8hxwv_eai-selfservice-dev" network: error adding host side routes for interface: calicfa03c2c5b1, error: route (Ifindex: 439, Dst: 100.80.1.65/32, Scope: 253) already exists for an interface other than 'calicfa03c2c5b1'
You can see here, that it tries to assign the IP addresses 100.80.1.62, .63 and .64, which are all in use. Next it startet the pod successfull with 100.80.1.67.
Next I checked one of the exisiting pods, but everything looks good as far as I can tell:
k get pod -owide --all-namespaces|grep 100.80.1.63
eai-dev default-http-backend-6fd4978fb-2hkx4 1/1 Running 0 37h 100.80.1.63 k8s-worker-01.example.com <none> <none>
And to be sure I check the ipamhandle of this pod too:
k get ipamhandle k8s-pod-network.5a1d961664df5e922c225bc06e69d0fc60aedf6eaa96670ecd5febc7cb160262 -oyaml
apiVersion: crd.projectcalico.org/v1
kind: IPAMHandle
metadata:
annotations:
projectcalico.org/metadata: '{"creationTimestamp":null}'
creationTimestamp: "2020-08-25T23:45:08Z"
generation: 1
name: k8s-pod-network.5a1d961664df5e922c225bc06e69d0fc60aedf6eaa96670ecd5febc7cb160262
resourceVersion: "971980875"
selfLink: /apis/crd.projectcalico.org/v1/ipamhandles/k8s-pod-network.5a1d961664df5e922c225bc06e69d0fc60aedf6eaa96670ecd5febc7cb160262
uid: 467c0bca-4a32-4179-b214-3e286cadb783
spec:
block:
100.80.1.0/26: 1
handleID: k8s-pod-network.5a1d961664df5e922c225bc06e69d0fc60aedf6eaa96670ecd5febc7cb160262
(even though I’m not sure whether this helps.)
I checked the ipamblock of the node, which is huge and shortened here, but you can see, that the IP addresses are not listet under unallocated:
apiVersion: crd.projectcalico.org/v1
kind: IPAMBlock
metadata:
annotations:
projectcalico.org/metadata: '{"creationTimestamp":null}'
creationTimestamp: "2020-07-12T11:09:10Z"
generation: 155
name: 100-80-1-0-26
resourceVersion: "971980877"
selfLink: /apis/crd.projectcalico.org/v1/ipamblocks/100-80-1-0-26
uid: 1c670855-c430-11ea-b730-00505684b2d0
spec:
affinity: host:k8s-worker-00.example.com
allocations:
- null
- null
- 15
- 11
- 29
- 40
- 51
- 12
- 13
- 14
- null
- 0
- null
- 1
- 2
- null
- null
- null
- null
- 3
- 16
- 4
- 5
- 6
- 7
- 8
- 9
- 17
- 10
- 18
- 19
- 20
- 21
- 22
- 23
- 24
- 25
- 26
- 27
- 28
- 30
- 31
- 32
- 33
- 34
- 35
- 36
- 37
- 38
- 39
- 41
- 42
- 43
- 44
- 45
- 46
- 47
- 48
- 49
- 50
- 52
- 53
- 54
- 55
attributes:
- handle_id: "k8s-pod-network.dd372304a3d85e8900e0b940ce4d98936543fd403312ee151f6f9a178d08636d\r\neth0"
secondary:
namespace: rook-ceph-stage-primary
node: k8s-worker-00.example.com
pod: rook-ceph-stage-primary-backup-pdm7z
- handle_id: "k8s-pod-network.518cee30324d9bee2c1a80a78fb41055ea5609298833e0a042ab9097d51be239\r\neth0"
secondary:
namespace: cxa-stage
node: k8s-worker-00.example.com
pod: release-name-zookeeper-1
[...]
- handle_id: k8s-pod-network.44333bb9ad1fa32a354121431cb75c4e4b8996587793434eeb0c493ea6e4893d
secondary:
namespace: eai-dev
node: k8s-worker-01.example.com
pod: comp00000006-66c689ff6f-x9472
- handle_id: k8s-pod-network.5a1d961664df5e922c225bc06e69d0fc60aedf6eaa96670ecd5febc7cb160262
secondary:
namespace: eai-dev
node: k8s-worker-01.example.com
pod: default-http-backend-6fd4978fb-2hkx4
cidr: 100.80.1.0/26
deleted: false
strictAffinity: false
unallocated:
- 0
- 1
- 10
- 12
- 15
- 16
- 17
- 18
One strange thing I noticed here, is that under attributes it lists another node (k8s-worker-00.example.com)which has been deleted and is no longer part of the cluster. I’m not sure if this is a problem. Maybe this happend because calico reused the CIDR range for this node. I checked the node ipamhandle too, but this looks good to me too:
apiVersion: crd.projectcalico.org/v1
kind: IPAMHandle
metadata:
annotations:
projectcalico.org/metadata: '{"creationTimestamp":null}'
creationTimestamp: "2020-08-24T23:28:51Z"
generation: 1
name: ipip-tunnel-addr-k8s-worker-01.example.com
resourceVersion: "970070259"
selfLink: /apis/crd.projectcalico.org/v1/ipamhandles/ipip-tunnel-addr-k8s-worker-01.example.com
uid: d80ea18c-4490-446a-b079-ef286a17cfe0
spec:
block:
100.80.1.64/26: 1
handleID: ipip-tunnel-addr-k8s-worker-01.example.com
And last here are the calico-node logs for this particular pod, but it seems to only log the successful assignment of the final IP address:
k logs -n kube-system calico-node-8l5pp |grep nginx-ingress-controller-6664bc7855-8hxwv
2020-08-26 13:22:57.551 [INFO][22004] calc_graph.go 392: Local endpoint updated id=WorkloadEndpoint(node=k8s-worker-01.example.com, orchestrator=k8s, workload=eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv, name=eth0)
2020-08-26 13:22:57.555 [INFO][22004] int_dataplane.go 834: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv" endpoint_id:"eth0" > endpoint:<state:"active" name:"calicfa03c2c5b1" profile_ids:"kns.eai-selfservice-dev" profile_ids:"ksa.eai-selfservice-dev.eai-selfservice-dev-nginx-ingress-serviceaccount" ipv4_nets:"100.80.1.67/32" tiers:<name:"default" ingress_policies:"eai-selfservice-dev/knp.default.allow-ingress-access" ingress_policies:"eai-selfservice-dev/knp.default.allow-mssql" ingress_policies:"eai-selfservice-dev/knp.default.allow-own-namepace" ingress_policies:"eai-selfservice-dev/knp.default.allow-prometheus" ingress_policies:"eai-selfservice-dev/knp.default.allow-prometheus-springboot" ingress_policies:"eai-selfservice-dev/knp.default.default-deny-do-not-delete" egress_policies:"eai-selfservice-dev/knp.default.allow-active-directory" egress_policies:"eai-selfservice-dev/knp.default.allow-dns-access" egress_policies:"eai-selfservice-dev/knp.default.allow-mssql" egress_policies:"eai-selfservice-dev/knp.default.allow-nginx-apiserver-access" egress_policies:"eai-selfservice-dev/knp.default.allow-own-namepace" egress_policies:"eai-selfservice-dev/knp.default.allow-pki-cert" egress_policies:"eai-selfservice-dev/knp.default.allow-smtp" egress_policies:"eai-selfservice-dev/knp.default.allow-tibco-ems" egress_policies:"eai-selfservice-dev/knp.default.allow-tls" egress_policies:"eai-selfservice-dev/knp.default.default-deny-do-not-delete" > >
2020-08-26 13:22:57.555 [INFO][22004] endpoint_mgr.go 545: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"}
2020-08-26 13:22:57.556 [INFO][22004] endpoint_mgr.go 572: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"}
2020-08-26 13:22:57.556 [INFO][22004] endpoint_mgr.go 438: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"}
2020-08-26 13:22:57.557 [INFO][22004] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"}
2020-08-26 13:22:57.635 [INFO][22004] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"} ipVersion=0x4 status="up"
2020-08-26 13:22:57.635 [INFO][22004] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"eai-selfservice-dev/nginx-ingress-controller-6664bc7855-8hxwv", EndpointId:"eth0"} status="up"
Context
We did redeploy calico before, because we needed to change the pod IP CIDR. For this reason we completely deleted and reapplied calico with all CRs and CRDs. All the pods on this node has been started after the pod IP CIDR change.
If I missed to provide some important information please let me know.
Your Environment
- Calico version v3.11.3
- Orchestrator version (e.g. kubernetes, mesos, rkt): k8s 1.17.6
- Operating System and version: Flatcar Container Linux 2345.3.1
About this issue
- Original URL
- State: closed
- Created 4 years ago
- Comments: 23 (9 by maintainers)
HI @caseydavenport, I upgraded the first cluster to 3.17.0, but unfortunately I still see the same errors in calico-kube-controller. I increased the loglevel to debug:
[…]
I split the logs in multiple code blocks since the “Releasing all IPs”-blocks are examples and logged multiple times for different ipamhandles. The “Node still exists, continue”-lines change every time it appears for different hosts and different host counts.
Merged a cherry-pick to v3.17.0: https://github.com/projectcalico/libcalico-go/pull/1346
@TheKangaroo I’m very sorry for the delay on this one. I’ve taken a look at the logs and this is my understanding of the issue:
Yeah, it looks very much like this is a result of “bad” data still in the IPAM allocations from the previous bug: https://github.com/projectcalico/cni-plugin/issues/821
There appears to be a mismatch in the Handle resource names - which seem to be properly formatted - and the attributes in the IPAM blocks - which seem to have the invalid format
k8s-pod-network.<id>\r\neth0The controller tries to release the allocation using the invalid handle, finds that no Handle object exists which matches the bad name, and hits this block: https://github.com/projectcalico/kube-controllers/blob/master/pkg/controllers/node/ipam.go#L208
When it comes around again to retry, the allocations are obviously still there since we didn’t release anything, and it tries the whole thing over again. What I am not 100% on is how this is causing duplicate IP addresses to be assigned in the cluster, but I can imagine that it is related.
I think that a change like this would fix the endless retries that you are seeing by allowing the code to properly compare the correctly formatted handle IDs with the improperly formatted ones: https://github.com/projectcalico/libcalico-go/pull/1345
@fasaxc WDYT?
Actually we already drained, deleted, redeployed and rejoined every node in the cluster after reinstalling calico, so this should be fine.
@fasaxc assisted me in troubleshooting this issue in calico slack (https://calicousers.slack.com/archives/C0BCA117T/p1598449811033700) but I could no longer reproduce this issue. Maybe it is best to close this issue and I’ll come back with more information when I see this happen again.