search

projectcalico / calico

Cloud native networking and network security
https://docs.tigera.io/calico/latest/about/
Apache License 2.0
6.03k stars 1.34k forks source link

why pod just become running but cni port is not ready #5683

Closed lklkxcxc closed 2 years ago

lklkxcxc commented 2 years ago

Expected Behavior

When pod just become running ，The pod's network is ready.

Current Behavior

The pod just become running but cni port is not ready，Can not ping coredns service ip in inner pod . it's ping ok coredns service ip after for a minute .

Possible Solution

Steps to Reproduce (for bugs)

The Calico assign cni port to pod logs：

2022-03-01 03:46:10.921 [WARNING][65] health.go 190: Reporter failed readiness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f839af247e9a3, ext:87507073724, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:46:18.037 [INFO][65] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=30.193273163s
2022-03-01 03:46:18.037 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2022-03-01 03:46:18.041 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2022-03-01 03:46:19.235 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=31391.870118
2022-03-01 03:46:19.235 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:46:19.235 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2022-03-01 03:46:19.235 [INFO][65] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2022-03-01 03:46:20.920 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:true, Ready:true}

2022-03-01 03:46:40.928 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:false, Ready:false}
2022-03-01 03:46:40.929 [WARNING][65] health.go 184: Reporter failed liveness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83a2ce0b0396, ext:118899102944, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:46:40.929 [WARNING][65] health.go 190: Reporter failed readiness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83a2ce0b0396, ext:118899102944, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:46:49.749 [INFO][65] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=30.513886701s
2022-03-01 03:46:49.749 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2022-03-01 03:46:49.749 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2022-03-01 03:46:49.750 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2022-03-01 03:46:49.750 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2022-03-01 03:46:49.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2022-03-01 03:46:49.830 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2022-03-01 03:46:49.832 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2022-03-01 03:46:49.836 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2022-03-01 03:46:57.353 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=38117.977195
2022-03-01 03:46:57.353 [INFO][65] int_dataplane.go 797: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali12d4a061371", State:"down"}
2022-03-01 03:46:57.353 [INFO][65] int_dataplane.go 797: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali12d4a061371", State:"up"}
2022-03-01 03:46:57.353 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:46:57.355 [INFO][65] endpoint_mgr.go 314: Workload interface came up, marking for reconfiguration. ifaceName="cali12d4a061371"
2022-03-01 03:46:57.355 [INFO][65] endpoint_mgr.go 923: Applying /proc/sys configuration to interface. ifaceName="cali12d4a061371"
2022-03-01 03:46:57.429 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2022-03-01 03:46:57.432 [INFO][65] route_table.go 528: Syncing routes: removing old route. dest=10.233.148.249/32 ifaceName="cali12d4a061371" ipVersion=0x4
2022-03-01 03:46:57.433 [INFO][65] conntrack.go 78: Removing conntrack flows ip=10.233.148.249
2022-03-01 03:46:57.438 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2022-03-01 03:46:59.134 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=1780.88176
2022-03-01 03:46:59.135 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:46:59.135 [INFO][65] route_table.go 222: Queueing a resync of routing table. ipVersion=0x4
2022-03-01 03:46:59.630 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=495.26922299999995
2022-03-01 03:46:59.630 [INFO][65] int_dataplane.go 812: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.mapSet{}}
2022-03-01 03:46:59.630 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.mapSet{}}
2022-03-01 03:46:59.630 [INFO][65] int_dataplane.go 812: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.Set(nil)}
2022-03-01 03:46:59.630 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.Set(nil)}
2022-03-01 03:46:59.630 [INFO][65] int_dataplane.go 812: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2022-03-01 03:46:59.630 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali12d4a061371", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2022-03-01 03:46:59.630 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:46:59.631 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=0.165587
2022-03-01 03:46:59.631 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:46:59.631 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2022-03-01 03:46:59.631 [INFO][65] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2022-03-01 03:47:00.921 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:true, Ready:true}
2022-03-01 03:47:20.920 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:false, Ready:false}
2022-03-01 03:47:20.920 [WARNING][65] health.go 184: Reporter failed liveness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83ace59e49b1, ext:159294630762, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:47:20.920 [WARNING][65] health.go 190: Reporter failed readiness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83ace59e49b1, ext:159294630762, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:47:32.429 [INFO][65] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=32.798237426s
2022-03-01 03:47:32.429 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=32798.775065
2022-03-01 03:47:32.430 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:47:32.430 [INFO][65] route_table.go 222: Queueing a resync of routing table. ipVersion=0x4
2022-03-01 03:47:33.329 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:true, Ready:true}
2022-03-01 03:47:34.132 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=1702.468903
2022-03-01 03:47:34.132 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:47:34.132 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2022-03-01 03:47:34.134 [INFO][65] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2022-03-01 03:48:00.930 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:false, Ready:false}
2022-03-01 03:48:00.931 [WARNING][65] health.go 184: Reporter failed liveness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83b587ea4db1, ext:193796295914, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:48:00.931 [WARNING][65] health.go 190: Reporter failed readiness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83b587ea4db1, ext:193796295914, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:48:06.635 [INFO][65] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=32.501036129s
2022-03-01 03:48:06.635 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2022-03-01 03:48:06.642 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2022-03-01 03:48:07.945 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=33812.497661
2022-03-01 03:48:07.945 [INFO][65] int_dataplane.go 782: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"ksa.default.default" > profile:<> 
2022-03-01 03:48:07.945 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pri-ksa.default.default" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.945 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2022-03-01 03:48:07.945 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pro-ksa.default.default" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.945 [INFO][65] int_dataplane.go 782: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"default/busybox" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali12d4a061371" mac:"3a:d2:2e:aa:65:d5" profile_ids:"kns.default" profile_ids:"ksa.default.default" ipv4_nets:"10.233.148.249/32" > 
2022-03-01 03:48:07.945 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:48:07.945 [INFO][65] endpoint_mgr.go 476: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"}
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali12d4a061371" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali12d4a061371" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-sm-cali12d4a061371" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] endpoint_mgr.go 503: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"}
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch-1" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch-1" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.946 [INFO][65] endpoint_mgr.go 923: Applying /proc/sys configuration to interface. ifaceName="cali12d4a061371"
2022-03-01 03:48:07.947 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-set-endpoint-mark-1" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.947 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-set-endpoint-mark" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.947 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-endpoint-mark" ipVersion=0x4 table="filter"
2022-03-01 03:48:07.947 [INFO][65] endpoint_mgr.go 411: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"}
2022-03-01 03:48:07.947 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"}
2022-03-01 03:48:07.951 [INFO][65] route_table.go 545: Syncing routes: adding new route. ifaceName="cali12d4a061371" ipVersion=0x4 targetCIDR=10.233.148.249/32
2022-03-01 03:48:08.035 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2022-03-01 03:48:09.632 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"} ipVersion=0x4 status="up"
2022-03-01 03:48:09.633 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"default/busybox", EndpointId:"eth0"} status="up"
2022-03-01 03:48:09.633 [INFO][65] int_dataplane.go 921: Finished applying updates to dataplane. msecToApply=1687.568631
2022-03-01 03:48:09.633 [INFO][65] int_dataplane.go 907: Applying dataplane updates
2022-03-01 03:48:09.633 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2022-03-01 03:48:09.633 [INFO][65] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2022-03-01 03:48:10.930 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:true, Ready:true}
2022-03-01 03:48:30.920 [INFO][65] health.go 178: Overall health status changed lastSummary=&health.HealthReport{Live:false, Ready:false}
2022-03-01 03:48:30.920 [WARNING][65] health.go 184: Reporter failed liveness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83be65c4353f, ext:229297115785, loc:(*time.Location)(0x2c441e0)}}
2022-03-01 03:48:30.928 [WARNING][65] health.go 190: Reporter failed readiness checks name="int_dataplane" reporter-state=&health.reporterState{name:"int_dataplane", reports:health.HealthReport{Live:true, Ready:true}, timeout:20000000000, latest:health.HealthReport{Live:true, Ready:true}, timestamp:time.Time{wall:0xc07f83be65c4353f, ext:229297115785, loc:(*time.Location)(0x2c441e0)}}

Context

Your Environment

caseydavenport commented 2 years ago

Calico version: v3.7.3

You need to upgrade - this version of Calico is well outside of support. Please reopen this issue if you can reproduce on a modern version of Calico.