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

calico-kube-controllers and calico-node are not ready (CrashLoopBackOff) #4935

Closed
HoseinGhanbari opened this issue Sep 15, 2021 · 5 comments
Closed

calico-kube-controllers and calico-node are not ready (CrashLoopBackOff) #4935

HoseinGhanbari opened this issue Sep 15, 2021 · 5 comments
Labels
kind/support

Comments

@HoseinGhanbari
Copy link

I deployed a brand new k8s cluster using kubespray, everything works fine but all of the calico related pods are not ready. And after many hours of debugging I couldn't find the reason why calico pods are crashing. I even disabled/stopped the entire firewalld service but nothing changed.

One other important thing is that calicoctl node status output is not stable and every time gets called show something different:

Calico process is not running.

Calico process is running.

None of the BGP backend processes (BIRD or GoBGP) are running.

Calico process is running.

IPv4 BGP status
+----------------+-------------------+-------+----------+---------+
|  PEER ADDRESS  |     PEER TYPE     | STATE |  SINCE   |  INFO   |
+----------------+-------------------+-------+----------+---------+
| 192.168.231.42 | node-to-node mesh | start | 06:23:41 | Passive |
+----------------+-------------------+-------+----------+---------+

IPv6 BGP status
No IPv6 peers found.

Another log that shown up often is the following message:

bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory

Also tried changing IP_AUTODETECTION_METHOD with each of the following but nothing changed:

kubectl set env daemonset/calico-node -n kube-system IP_AUTODETECTION_METHOD=can-reach=www.google.com
kubectl set env daemonset/calico-node -n kube-system IP_AUTODETECTION_METHOD=can-reach=8.8.8.8
kubectl set env daemonset/calico-node -n kube-system IP_AUTODETECTION_METHOD=interface=eth1
kubectl set env daemonset/calico-node -n kube-system IP_AUTODETECTION_METHOD=interface=eth.*

Expected Behavior

All pods, daemonset, deployment and replicaset related to calico should be in READY state.

Current Behavior

All pods, daemonset, deployment and replicaset related to calico is in NOT READY state.

Possible Solution

Nothing yet, I am asking for help on how to debug / overcome this issue.

Steps to Reproduce (for bugs)

Its the latest version of kubespray with the following Context & Environment.

git reflog

7e4b176 HEAD@{0}: clone: from https://github.com/kubernetes-sigs/kubespray.git

Context

I'm trying to deploy a k8s cluster which has one master and one worker node. Also note that the servers taking part in this cluster are located in an almost airgapped/offline enviroment with limited access to global internet, of course the ansible process of deploying cluster using kubespray was successful but I'm facing this issue with calico pods.

Your Environment

cat inventory/mycluster/hosts.yaml

all:
  hosts:
    node1:
      ansible_host: 192.168.231.41
      ansible_port: 32244
      ip: 192.168.231.41
      access_ip: 192.168.231.41
    node2:
      ansible_host: 192.168.231.42
      ansible_port: 32244
      ip: 192.168.231.42
      access_ip: 192.168.231.42
  children:
    kube_control_plane:
      hosts:
        node1:
    kube_node:
      hosts:
        node1:
        node2:
    etcd:
      hosts:
        node1:
    k8s_cluster:
      children:
        kube_control_plane:
        kube_node:
    calico_rr:
      hosts: {}

calicoctl version

Client Version:    v3.19.2
Git commit:        6f3d4900
Cluster Version:   v3.19.2
Cluster Type:      kubespray,bgp,kubeadm,kdd,k8s

cat /etc/centos-release

CentOS Linux release 7.9.2009 (Core)

uname -r

3.10.0-1160.42.2.el7.x86_64

kubectl version

Client Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.4", GitCommit:"3cce4a82b44f032d0cd1a1790e6d2f5a55d20aae", GitTreeState:"clean", BuildDate:"2021-08-11T18:16:05Z", GoVersion:"go1.16.7", Compiler:"gc", Platform:"linux/amd64"}

Server Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.4", GitCommit:"3cce4a82b44f032d0cd1a1790e6d2f5a55d20aae", GitTreeState:"clean", BuildDate:"2021-08-11T18:10:22Z", GoVersion:"go1.16.7", Compiler:"gc", Platform:"linux/amd64"}

 kubectl get nodes -o wide

NAME    STATUS   ROLES                  AGE   VERSION   INTERNAL-IP      EXTERNAL-IP   OS-IMAGE                KERNEL-VERSION                CONTAINER-RUNTIME
node1   Ready    control-plane,master   19h   v1.21.4   192.168.231.41   <none>        CentOS Linux 7 (Core)   3.10.0-1160.42.2.el7.x86_64   docker://20.10.8
node2   Ready    <none>                 19h   v1.21.4   192.168.231.42   <none>        CentOS Linux 7 (Core)   3.10.0-1160.42.2.el7.x86_64   docker://20.10.8

kubectl get all --all-namespaces -o wide

NAMESPACE     NAME                                           READY   STATUS             RESTARTS   AGE   IP               NODE    NOMINATED NODE   READINESS GATES
kube-system   pod/calico-kube-controllers-8575b76f66-57zw4   0/1     CrashLoopBackOff   327        19h   192.168.231.42   node2   <none>           <none>
kube-system   pod/calico-node-4hkzb                          0/1     Running            245        14h   192.168.231.42   node2   <none>           <none>
kube-system   pod/calico-node-hznhc                          0/1     Running            245        14h   192.168.231.41   node1   <none>           <none>
kube-system   pod/coredns-8474476ff8-b6lqz                   1/1     Running            0          19h   10.233.96.1      node2   <none>           <none>
kube-system   pod/coredns-8474476ff8-gdkml                   1/1     Running            0          19h   10.233.90.1      node1   <none>           <none>
kube-system   pod/dns-autoscaler-7df78bfcfb-xnn4r            1/1     Running            0          19h   10.233.90.2      node1   <none>           <none>
kube-system   pod/kube-apiserver-node1                       1/1     Running            0          19h   192.168.231.41   node1   <none>           <none>
kube-system   pod/kube-controller-manager-node1              1/1     Running            0          19h   192.168.231.41   node1   <none>           <none>
kube-system   pod/kube-proxy-dmw22                           1/1     Running            0          19h   192.168.231.41   node1   <none>           <none>
kube-system   pod/kube-proxy-wzpnv                           1/1     Running            0          19h   192.168.231.42   node2   <none>           <none>
kube-system   pod/kube-scheduler-node1                       1/1     Running            0          19h   192.168.231.41   node1   <none>           <none>
kube-system   pod/nginx-proxy-node2                          1/1     Running            0          19h   192.168.231.42   node2   <none>           <none>
kube-system   pod/nodelocaldns-6h5q2                         1/1     Running            0          19h   192.168.231.42   node2   <none>           <none>
kube-system   pod/nodelocaldns-7fwbd                         1/1     Running            0          19h   192.168.231.41   node1   <none>           <none>

NAMESPACE     NAME                 TYPE        CLUSTER-IP   EXTERNAL-IP   PORT(S)                  AGE   SELECTOR
default       service/kubernetes   ClusterIP   10.233.0.1   <none>        443/TCP                  19h   <none>
kube-system   service/coredns      ClusterIP   10.233.0.3   <none>        53/UDP,53/TCP,9153/TCP   19h   k8s-app=kube-dns

NAMESPACE     NAME                          DESIRED   CURRENT   READY   UP-TO-DATE   AVAILABLE   NODE SELECTOR            AGE   CONTAINERS    IMAGES                                     SELECTOR
kube-system   daemonset.apps/calico-node    2         2         0       2            0           kubernetes.io/os=linux   19h   calico-node   quay.io/calico/node:v3.19.2                k8s-app=calico-node
kube-system   daemonset.apps/kube-proxy     2         2         2       2            2           kubernetes.io/os=linux   19h   kube-proxy    k8s.gcr.io/kube-proxy:v1.21.4              k8s-app=kube-proxy
kube-system   daemonset.apps/nodelocaldns   2         2         2       2            2           kubernetes.io/os=linux   19h   node-cache    k8s.gcr.io/dns/k8s-dns-node-cache:1.17.1   k8s-app=nodelocaldns

NAMESPACE     NAME                                      READY   UP-TO-DATE   AVAILABLE   AGE   CONTAINERS                IMAGES                                                       SELECTOR
kube-system   deployment.apps/calico-kube-controllers   0/1     1            0           19h   calico-kube-controllers   quay.io/calico/kube-controllers:v3.19.2                      k8s-app=calico-kube-controllers
kube-system   deployment.apps/coredns                   2/2     2            2           19h   coredns                   k8s.gcr.io/coredns/coredns:v1.8.0                            k8s-app=kube-dns
kube-system   deployment.apps/dns-autoscaler            1/1     1            1           19h   autoscaler                k8s.gcr.io/cpa/cluster-proportional-autoscaler-amd64:1.8.3   k8s-app=dns-autoscaler

NAMESPACE     NAME                                                 DESIRED   CURRENT   READY   AGE   CONTAINERS                IMAGES                                                       SELECTOR
kube-system   replicaset.apps/calico-kube-controllers-8575b76f66   1         1         0       19h   calico-kube-controllers   quay.io/calico/kube-controllers:v3.19.2                      k8s-app=calico-kube-controllers,pod-template-hash=8575b76f66
kube-system   replicaset.apps/coredns-8474476ff8                   2         2         2       19h   coredns                   k8s.gcr.io/coredns/coredns:v1.8.0                            k8s-app=kube-dns,pod-template-hash=8474476ff8
kube-system   replicaset.apps/dns-autoscaler-7df78bfcfb            1         1         1       19h   autoscaler                k8s.gcr.io/cpa/cluster-proportional-autoscaler-amd64:1.8.3   k8s-app=dns-autoscaler,pod-template-hash=7df78bfcfb
@caseydavenport
Copy link
Member

@HoseinGhanbari I wonder if you might be hitting this issue, which was fixed by increasing the timeout on liveness probes: #4911

Could you share the logs from your kube-controllers and calico/node pods so I can see if there are any obvious errors?

@HoseinGhanbari
Copy link
Author

BTW This is so weird... Let me know if you need some other logs.

kubectl logs -n kube-system pod/calico-kube-controllers-6bbf4785f-r6x2x

2021-09-21 17:52:24.467 [INFO][1] main.go 92: Loaded configuration from environment config=&config.Config{LogLevel:"info", WorkloadEndpointWorkers:1, ProfileWorkers:1, PolicyWorkers:1, NodeWorkers:1, Kubeconfig:"", DatastoreType:"kubernetes"}
W0921 17:52:24.662438       1 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
2021-09-21 17:52:24.667 [INFO][1] main.go 113: Ensuring Calico datastore is initialized
2021-09-21 17:52:25.067 [INFO][1] main.go 153: Getting initial config snapshot from datastore
2021-09-21 17:52:25.681 [INFO][1] main.go 156: Got initial config snapshot
2021-09-21 17:52:25.762 [INFO][1] watchersyncer.go 89: Start called
2021-09-21 17:52:25.763 [INFO][1] main.go 173: Starting status report routine
2021-09-21 17:52:25.763 [INFO][1] main.go 182: Starting Prometheus metrics server on port 9094
2021-09-21 17:52:25.763 [INFO][1] main.go 418: Starting controller ControllerType="Node"
2021-09-21 17:52:25.763 [INFO][1] node_controller.go 143: Starting Node controller
2021-09-21 17:52:25.963 [INFO][1] resources.go 349: Main client watcher loop
2021-09-21 17:52:25.964 [INFO][1] watchersyncer.go 127: Sending status update Status=wait-for-ready
2021-09-21 17:52:25.965 [INFO][1] node_syncer.go 65: Node controller syncer status updated: wait-for-ready
2021-09-21 17:52:25.965 [INFO][1] watchersyncer.go 147: Starting main event processing loop
2021-09-21 17:52:25.965 [INFO][1] watchercache.go 174: Full resync is required ListRoot="/calico/ipam/v2/assignment/"
2021-09-21 17:52:25.966 [INFO][1] watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:52:26.566 [INFO][1] watchercache.go 271: Sending synced update ListRoot="/calico/ipam/v2/assignment/"
2021-09-21 17:52:26.662 [INFO][1] watchersyncer.go 127: Sending status update Status=resync
2021-09-21 17:52:26.662 [INFO][1] node_syncer.go 65: Node controller syncer status updated: resync
2021-09-21 17:52:26.662 [INFO][1] watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:52:26.668 [INFO][1] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:52:26.762 [INFO][1] watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:52:26.762 [INFO][1] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2021-09-21 17:52:26.763 [INFO][1] watchersyncer.go 127: Sending status update Status=in-sync
2021-09-21 17:52:26.763 [INFO][1] node_syncer.go 65: Node controller syncer status updated: in-sync
2021-09-21 17:52:26.861 [INFO][1] node_controller.go 159: Node controller is now running
2021-09-21 17:52:26.862 [INFO][1] ipam.go 69: Synchronizing IPAM data
2021-09-21 17:52:27.165 [INFO][1] hostendpoints.go 90: successfully synced all hostendpoints
2021-09-21 17:52:27.622 [INFO][1] ipam.go 78: Node and IPAM data is in sync

kubectl logs -n kube-system pod/calico-node-h5bz8

2021-09-21 17:53:47.751 [INFO][32] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'wireguard-tunnel-addr-node1'
2021-09-21 17:53:48.353 [INFO][32] tunnel-ip-allocator/allocateip.go 290: Current address is still valid, do nothing currentAddr="10.233.90.0" type="ipipTunnelAddress"
2021-09-21 17:53:48.362 [INFO][32] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'vxlan-tunnel-addr-node1'
Calico node started successfully
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory

kubectl logs -n kube-system pod/calico-node-rmx9k

2021-09-21 17:50:46.901 [INFO][32] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'wireguard-tunnel-addr-node2'
2021-09-21 17:50:47.163 [INFO][32] tunnel-ip-allocator/allocateip.go 290: Current address is still valid, do nothing currentAddr="10.233.96.0" type="ipipTunnelAddress"
2021-09-21 17:50:47.186 [INFO][32] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'vxlan-tunnel-addr-node2'
Calico node started successfully
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
2021-09-21 17:50:58.864 [INFO][70] confd/config.go 81: Skipping confd config file.
2021-09-21 17:50:58.865 [INFO][70] confd/run.go 17: Starting calico-confd
2021-09-21 17:50:58.973 [INFO][67] tunnel-ip-allocator/watchersyncer.go 89: Start called
2021-09-21 17:50:59.169 [INFO][67] tunnel-ip-allocator/watchersyncer.go 127: Sending status update Status=wait-for-ready
2021-09-21 17:50:59.169 [INFO][67] tunnel-ip-allocator/watchersyncer.go 147: Starting main event processing loop
2021-09-21 17:50:59.170 [INFO][67] tunnel-ip-allocator/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/nodes/node2"
2021-09-21 17:50:59.261 [INFO][67] tunnel-ip-allocator/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2021-09-21 17:50:59.762 [INFO][67] tunnel-ip-allocator/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes/node2"
2021-09-21 17:50:59.763 [INFO][67] tunnel-ip-allocator/watchersyncer.go 127: Sending status update Status=resync
2021-09-21 17:50:59.763 [INFO][67] tunnel-ip-allocator/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:50:59.965 [INFO][67] tunnel-ip-allocator/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
2021-09-21 17:50:59.968 [INFO][67] tunnel-ip-allocator/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:50:59.968 [INFO][67] tunnel-ip-allocator/watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2021-09-21 17:50:59.968 [INFO][67] tunnel-ip-allocator/watchersyncer.go 127: Sending status update Status=in-sync
2021-09-21 17:51:00.263 [INFO][67] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'wireguard-tunnel-addr-node2'
W0921 17:51:00.264946      70 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
2021-09-21 17:51:00.366 [INFO][66] cni-config-monitor/token_watch.go 40: Watching contents for changes. directory="/var/run/secrets/kubernetes.io/serviceaccount/"
2021-09-21 17:51:00.367 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 1212: Updated with new cluster IP CIDRs: []
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 1203: Updated with new external IP CIDRs: []
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 1222: Updated with new Loadbalancer IP CIDRs: []
2021-09-21 17:51:00.368 [INFO][70] confd/watchersyncer.go 89: Start called
2021-09-21 17:51:00.368 [INFO][70] confd/client.go 376: Source SourceRouteGenerator readiness changed, ready=true
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
2021-09-21 17:51:00.561 [INFO][70] confd/watchersyncer.go 127: Sending status update Status=wait-for-ready
2021-09-21 17:51:00.663 [INFO][70] confd/watchersyncer.go 147: Starting main event processing loop
2021-09-21 17:51:00.761 [INFO][70] confd/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2021-09-21 17:51:00.764 [INFO][70] confd/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:51:00.765 [INFO][70] confd/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/bgpconfigurations"
2021-09-21 17:51:00.766 [INFO][70] confd/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/bgppeers"
2021-09-21 17:51:00.962 [INFO][70] confd/watchercache.go 174: Full resync is required ListRoot="/calico/ipam/v2/host/node2"
2021-09-21 17:51:01.077 [INFO][70] confd/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/bgppeers"
2021-09-21 17:51:01.166 [INFO][70] confd/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/bgpconfigurations"
2021-09-21 17:51:01.261 [INFO][70] confd/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:01.262 [INFO][70] confd/watchersyncer.go 127: Sending status update Status=resync
2021-09-21 17:51:01.262 [INFO][70] confd/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:01.264 [INFO][70] confd/client.go 897: Recompute BGP peerings: listenPort updated.; AS number updated.
2021-09-21 17:51:01.264 [INFO][70] confd/client.go 903: Updates included service advertisement changes.
2021-09-21 17:51:01.264 [INFO][70] confd/client.go 906: Starting route generator due to service advertisement update
2021-09-21 17:51:01.264 [INFO][67] tunnel-ip-allocator/allocateip.go 290: Current address is still valid, do nothing currentAddr="10.233.96.0" type="ipipTunnelAddress"
W0921 17:51:01.264675      70 client_config.go:615] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
2021-09-21 17:51:01.364 [INFO][67] tunnel-ip-allocator/ipam.go 1410: Releasing all IPs with handle 'vxlan-tunnel-addr-node2'
2021-09-21 17:51:01.467 [INFO][70] confd/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2021-09-21 17:51:01.467 [INFO][70] confd/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:01.564 [INFO][70] confd/routes.go 109: Starting RouteGenerator for Kubernetes services
2021-09-21 17:51:01.564 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:01.564 [INFO][70] confd/client.go 1203: Updated with new external IP CIDRs: []
2021-09-21 17:51:01.564 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:01.564 [INFO][70] confd/client.go 1212: Updated with new cluster IP CIDRs: []
2021-09-21 17:51:01.564 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:01.565 [INFO][70] confd/client.go 1222: Updated with new Loadbalancer IP CIDRs: []
2021-09-21 17:51:01.671 [INFO][70] confd/watchercache.go 271: Sending synced update ListRoot="/calico/ipam/v2/host/node2"
2021-09-21 17:51:01.671 [INFO][70] confd/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:02.266 [INFO][69] felix/logutils.go 82: Early screen log level set to info
2021-09-21 17:51:02.267 [INFO][70] confd/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:51:02.268 [INFO][70] confd/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:02.268 [INFO][70] confd/watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2021-09-21 17:51:02.268 [INFO][70] confd/watchersyncer.go 127: Sending status update Status=in-sync
2021-09-21 17:51:02.269 [INFO][70] confd/client.go 897: Recompute BGP peerings: HostBGPConfig(node=node1; name=ip_addr_v4) updated; HostBGPConfig(node=node1; name=ip_addr_v6) updated; HostBGPConfig(node=node1; name=network_v4) updated; HostBGPConfig(node=node1; name=rr_cluster_id) updated; node1 updated; HostBGPConfig(node=node2; name=ip_addr_v4) updated; HostBGPConfig(node=node2; name=ip_addr_v6) updated; HostBGPConfig(node=node2; name=network_v4) updated; HostBGPConfig(node=node2; name=rr_cluster_id) updated; node2 updated
2021-09-21 17:51:02.269 [INFO][70] confd/client.go 903: Updates included service advertisement changes.
2021-09-21 17:51:02.269 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 1203: Updated with new external IP CIDRs: []
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 1212: Updated with new cluster IP CIDRs: []
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 1267: Advertise global service ranges from this node
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 1222: Updated with new Loadbalancer IP CIDRs: []
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 376: Source SourceSyncer readiness changed, ready=true
2021-09-21 17:51:02.270 [INFO][70] confd/client.go 396: Data is now syncd, can start rendering templates
2021-09-21 17:51:02.372 [INFO][69] felix/daemon.go 147: Felix starting up GOMAXPROCS=4 builddate="2021-08-03T22:08:56+0000" gitcommit="3e92fe531ab589a6ab85d1d17760185b3c04a37b" version="v3.19.2"
2021-09-21 17:51:02.462 [INFO][69] felix/daemon.go 166: Kubernetes server override env vars. KUBERNETES_SERVICE_HOST="10.233.0.1" KUBERNETES_SERVICE_PORT="443"
2021-09-21 17:51:02.462 [INFO][69] felix/daemon.go 171: Loading configuration...
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "prometheusmetricsenabled"="False"
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "ignorelooserpf"="False"
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdscheme"=""
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdkeyfile"=""
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "prometheusprocessmetricsenabled"="True"
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "iptableslocktimeoutsecs"="10"
2021-09-21 17:51:02.667 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "healthenabled"="true"
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "usagereportingenabled"="False"
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdcafile"=""
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "chaininsertmode"="Insert"
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdendpoints"=""
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "healthhost"="localhost"
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "felixhostname"="node2"
2021-09-21 17:51:02.668 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "datastoretype"="kubernetes"
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdcertfile"=""
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "etcdaddr"=""
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "defaultendpointtohostaction"="RETURN"
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "logseverityscreen"="info"
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "prometheusmetricsport"="9091"
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "iptablesbackend"="Legacy"
2021-09-21 17:51:02.669 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "ipv6support"="False"
2021-09-21 17:51:02.670 [INFO][69] felix/env_var_loader.go 40: Found felix environment variable: "prometheusgometricsenabled"="True"
2021-09-21 17:51:02.670 [INFO][69] felix/daemon.go 197: Loading config file: /etc/calico/felix.cfg
2021-09-21 17:51:02.671 [INFO][69] felix/config_params.go 343: Merging in config from environment variable: map[chaininsertmode:Insert datastoretype:kubernetes defaultendpointtohostaction:RETURN etcdaddr: etcdcafile: etcdcertfile: etcdendpoints: etcdkeyfile: etcdscheme: felixhostname:node2 healthenabled:true healthhost:localhost ignorelooserpf:False iptablesbackend:Legacy iptableslocktimeoutsecs:10 ipv6support:False logseverityscreen:info prometheusgometricsenabled:True prometheusmetricsenabled:False prometheusmetricsport:9091 prometheusprocessmetricsenabled:True usagereportingenabled:False]
2021-09-21 17:51:02.671 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdcafile" source=environment variable
2021-09-21 17:51:02.671 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdcertfile" source=environment variable
2021-09-21 17:51:02.671 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdaddr" source=environment variable
2021-09-21 17:51:02.671 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdscheme" source=environment variable
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdkeyfile" source=environment variable
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 352: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdendpoints" source=environment variable
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:02.672 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:02.673 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:02.673 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:02.673 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:02.761 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:02.761 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:02.762 [INFO][70] confd/routes.go 117: RouteGenerator in sync
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:02.762 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:02.763 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:02.764 [INFO][69] felix/config_params.go 343: Merging in config from config file: map[LogFilePath:None LogSeverityFile:None LogSeveritySys:None MetadataAddr:None]
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:02.765 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:02.766 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:02.767 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:02.767 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:02.767 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
2021-09-21 17:51:02.767 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:03.095 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:03.095 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:03.096 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:03.096 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:03.096 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
bird: Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
2021-09-21 17:51:03.461 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 432: Parsing value for MetadataAddr: None (from config file)
2021-09-21 17:51:03.462 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 468: Parsed value for MetadataAddr:  (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 432: Parsing value for LogFilePath: None (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 468: Parsed value for LogFilePath:  (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityFile: None (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityFile:  (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 432: Parsing value for LogSeveritySys: None (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:03.463 [INFO][69] felix/config_params.go 468: Parsed value for LogSeveritySys:  (from config file)
2021-09-21 17:51:03.463 [INFO][69] felix/health.go 233: Health enabled.  Starting server. host="localhost" port=9099
2021-09-21 17:51:03.464 [INFO][69] felix/config_params.go 555: Encap disabled, disabling node poll (if KDD is in use).
2021-09-21 17:51:03.464 [INFO][69] felix/daemon.go 229: Connecting to datastore datastore="kubernetes"
bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
2021-09-21 17:51:03.763 [INFO][69] felix/daemon.go 236: Created datastore client
2021-09-21 17:51:03.968 [WARNING][69] felix/health.go 188: Reporter is not ready. name="felix-startup"
2021-09-21 17:51:04.271 [INFO][69] felix/health.go 196: Overall health status changed newStatus=&health.HealthReport{Live:true, Ready:false}
2021-09-21 17:51:04.467 [INFO][69] felix/daemon.go 903: Loaded ready flag kind="ClusterInformation" name="default" ready=true
2021-09-21 17:51:04.967 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird_ipam.cfg has been updated
2021-09-21 17:51:05.365 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird6_aggr.cfg has been updated
2021-09-21 17:51:05.367 [INFO][69] felix/daemon.go 883: No config of this type kind="FelixConfiguration" name="node.node2"
2021-09-21 17:51:05.561 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird_aggr.cfg has been updated
2021-09-21 17:51:05.870 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird6.cfg has been updated
2021-09-21 17:51:05.876 [INFO][69] felix/config_params.go 343: Merging in config from datastore (global): map[BPFEnabled:false BPFExternalServiceMode:Tunnel CalicoVersion:v3.19.2 ClusterGUID:77b463ba17864605b6c2804c0bcc305a ClusterType:kubespray,bgp,kubeadm,kdd,k8s IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0 WireguardEnabled:false]
2021-09-21 17:51:05.876 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:05.876 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:05.877 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:05.877 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:05.879 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:05.879 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:05.879 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:05.880 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:05.880 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:05.880 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:05.880 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:06.162 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:06.162 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:06.162 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:06.162 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:06.162 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:06.261 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:06.262 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:06.262 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:06.262 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:06.262 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:06.262 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:06.263 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 432: Parsing value for MetadataAddr: None (from config file)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 468: Parsed value for MetadataAddr:  (from config file)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 432: Parsing value for LogFilePath: None (from config file)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 468: Parsed value for LogFilePath:  (from config file)
2021-09-21 17:51:06.264 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityFile: None (from config file)
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityFile:  (from config file)
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 432: Parsing value for LogSeveritySys: None (from config file)
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 468: Parsed value for LogSeveritySys:  (from config file)
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 432: Parsing value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 468: Parsed value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:06.265 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: Info (from datastore (global))
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 471: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 432: Parsing value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 468: Parsed value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 432: Parsing value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:06.266 [INFO][69] felix/config_params.go 468: Parsed value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 432: Parsing value for BPFExternalServiceMode: Tunnel (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 468: Parsed value for BPFExternalServiceMode: tunnel (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 432: Parsing value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 468: Parsed value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 432: Parsing value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:06.267 [INFO][69] felix/config_params.go 468: Parsed value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:06.268 [INFO][69] felix/config_params.go 432: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2021-09-21 17:51:06.268 [INFO][69] felix/config_params.go 468: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2021-09-21 17:51:06.268 [INFO][69] felix/config_params.go 343: Merging in config from datastore (per-host): map[IpInIpTunnelAddr:10.233.96.0]
2021-09-21 17:51:06.268 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:06.268 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:06.269 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:06.270 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:06.270 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:06.270 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:06.270 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:06.270 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:06.271 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:06.272 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:06.272 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:06.272 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:06.363 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityFile: None (from config file)
2021-09-21 17:51:06.464 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityFile:  (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 432: Parsing value for LogSeveritySys: None (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 468: Parsed value for LogSeveritySys:  (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 432: Parsing value for MetadataAddr: None (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 468: Parsed value for MetadataAddr:  (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 432: Parsing value for LogFilePath: None (from config file)
2021-09-21 17:51:06.465 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 468: Parsed value for LogFilePath:  (from config file)
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 432: Parsing value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 468: Parsed value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 432: Parsing value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:06.466 [INFO][69] felix/config_params.go 468: Parsed value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 432: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 468: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 432: Parsing value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 468: Parsed value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: Info (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 471: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2021-09-21 17:51:06.467 [INFO][69] felix/config_params.go 432: Parsing value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 468: Parsed value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 432: Parsing value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 468: Parsed value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 432: Parsing value for BPFExternalServiceMode: Tunnel (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 468: Parsed value for BPFExternalServiceMode: tunnel (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:06.468 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpEnabled: true (from datastore (global))
bird: device1: Initializing
bird: direct1: Initializing
bird: Mesh_192_168_231_41: Initializing
bird: device1: Starting
bird: device1: Connected to table master
bird: device1: State changed to feed
bird: direct1: Starting
bird: direct1: Connected to table master
bird: direct1: State changed to feed
bird: Mesh_192_168_231_41: Starting
bird: Mesh_192_168_231_41: State changed to start
bird: Graceful restart started
bird: Started
bird: device1: State changed to up
bird: direct1: State changed to up
2021-09-21 17:51:06.668 [INFO][69] felix/daemon.go 291: Using Kubernetes datastore driver, sharing Kubernetes client with datastore driver.
2021-09-21 17:51:06.762 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird6_ipam.cfg has been updated
2021-09-21 17:51:06.867 [INFO][69] felix/daemon.go 316: Server Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.4", GitCommit:"3cce4a82b44f032d0cd1a1790e6d2f5a55d20aae", GitTreeState:"clean", BuildDate:"2021-08-11T18:10:22Z", GoVersion:"go1.16.7", Compiler:"gc", Platform:"linux/amd64"}

2021-09-21 17:51:06.868 [INFO][69] felix/health.go 133: Health of component changed lastReport=health.HealthReport{Live:true, Ready:false} name="felix-startup" newReport=&health.HealthReport{Live:true, Ready:true}
2021-09-21 17:51:06.868 [INFO][69] felix/health.go 230: Health enabled.  Server is already running. host="localhost" port=9099
bird: Reconfiguration requested by SIGHUP
bird: Reconfiguring
bird: device1: Reconfigured
2021-09-21 17:51:06.868 [INFO][69] felix/daemon.go 361: Successfully loaded configuration. GOMAXPROCS=4 builddate="2021-08-03T22:08:56+0000" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", WireguardEnabled:false, WireguardListeningPort:51820, WireguardRoutingRulePriority:99, WireguardInterfaceName:"wireguard.cali", WireguardMTU:0, BPFEnabled:false, BPFDisableUnprivileged:true, BPFLogLevel:"off", BPFDataIfacePattern:(*regexp.Regexp)(0xc0004e5cc0), BPFConnectTimeLoadBalancingEnabled:true, BPFExternalServiceMode:"tunnel", BPFKubeProxyIptablesCleanupEnabled:true, BPFKubeProxyMinSyncPeriod:1000000000, BPFKubeProxyEndpointSlicesEnabled:false, BPFExtToServiceConnmark:0, DebugBPFCgroupV2:"", DebugBPFMapRepinEnabled:true, DatastoreType:"kubernetes", FelixHostname:"node2", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"", EtcdCertFile:"", EtcdCaFile:"", EtcdEndpoints:[]string(nil), TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:false, IptablesBackend:"legacy", RouteRefreshInterval:90000000000, InterfaceRefreshInterval:90000000000, DeviceRouteSourceAddress:net.IP(nil), DeviceRouteProtocol:3, RemoveExternalRoutes:true, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:10000000000, IptablesLockProbeIntervalMillis:50000000, FeatureDetectOverride:map[string]string(nil), IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, XDPRefreshInterval:90000000000, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, OpenstackRegion:"", InterfacePrefix:"cali", InterfaceExclude:[]*regexp.Regexp{(*regexp.Regexp)(0xc0004e5f40)}, ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", VXLANEnabled:false, VXLANPort:4789, VXLANVNI:4096, VXLANMTU:0, IPv4VXLANTunnelAddr:net.IP(nil), VXLANTunnelMACAddr:"", IpInIpEnabled:true, IpInIpMtu:0, IpInIpTunnelAddr:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xa, 0xe9, 0x60, 0x0}, AllowVXLANPacketsFromWorkloads:false, AllowIPIPPacketsFromWorkloads:false, AWSSrcDstCheck:"DoNothing", ServiceLoopPrevention:"Drop", ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:true, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsHost:"", PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"tcp", Port:0x16}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x44}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"udp", Port:0x35}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x43}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, NATOutgoingAddress:net.IP(nil), UsageReportingEnabled:false, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"77b463ba17864605b6c2804c0bcc305a", ClusterType:"kubespray,bgp,kubeadm,kdd,k8s", CalicoVersion:"v3.19.2", ExternalNodesCIDRList:[]string(nil), DebugMemoryProfilePath:"", DebugCPUProfilePath:"/tmp/felix-cpu-<timestamp>.pprof", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, DebugPanicAfter:0, DebugSimulateDataRace:false, RouteSource:"CalicoIPAM", RouteTableRange:idalloc.IndexRange{Min:1, Max:250}, IptablesNATOutgoingInterfaceFilter:"", SidecarAccelerationEnabled:false, XDPEnabled:true, GenericXDPEnabled:false, Variant:"Calico", MTUIfacePattern:(*regexp.Regexp)(0xc000a92320), internalOverrides:map[string]string{}, sourceToRawConfig:map[config.Source]map[string]string{0x1:map[string]string{"BPFEnabled":"false", "BPFExternalServiceMode":"Tunnel", "CalicoVersion":"v3.19.2", "ClusterGUID":"77b463ba17864605b6c2804c0bcc305a", "ClusterType":"kubespray,bgp,kubeadm,kdd,k8s", "IpInIpEnabled":"true", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "WireguardEnabled":"false"}, 0x2:map[string]string{"IpInIpTunnelAddr":"10.233.96.0"}, 0x3:map[string]string{"LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None"}, 0x4:map[string]string{"chaininsertmode":"Insert", "datastoretype":"kubernetes", "defaultendpointtohostaction":"RETURN", "felixhostname":"node2", "healthenabled":"true", "healthhost":"localhost", "ignorelooserpf":"False", "iptablesbackend":"Legacy", "iptableslocktimeoutsecs":"10", "ipv6support":"False", "logseverityscreen":"info", "prometheusgometricsenabled":"True", "prometheusmetricsenabled":"False", "prometheusmetricsport":"9091", "prometheusprocessmetricsenabled":"True", "usagereportingenabled":"False"}}, rawValues:map[string]string{"BPFEnabled":"false", "BPFExternalServiceMode":"Tunnel", "CalicoVersion":"v3.19.2", "ChainInsertMode":"Insert", "ClusterGUID":"77b463ba17864605b6c2804c0bcc305a", "ClusterType":"kubespray,bgp,kubeadm,kdd,k8s", "DatastoreType":"kubernetes", "DefaultEndpointToHostAction":"RETURN", "FelixHostname":"node2", "HealthEnabled":"true", "HealthHost":"localhost", "IpInIpEnabled":"true", "IpInIpTunnelAddr":"10.233.96.0", "IptablesBackend":"Legacy", "IptablesLockTimeoutSecs":"10", "Ipv6Support":"False", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeverityScreen":"info", "LogSeveritySys":"None", "MetadataAddr":"None", "PrometheusGoMetricsEnabled":"True", "PrometheusMetricsEnabled":"False", "PrometheusMetricsPort":"9091", "PrometheusProcessMetricsEnabled":"True", "ReportingIntervalSecs":"0", "UsageReportingEnabled":"False", "WireguardEnabled":"false", "ignorelooserpf":"False"}, Err:error(nil), loadClientConfigFromEnvironment:(func() (*apiconfig.CalicoAPIConfig, error))(0x15af6e0), useNodeResourceUpdates:false} gitcommit="3e92fe531ab589a6ab85d1d17760185b3c04a37b" version="v3.19.2"
2021-09-21 17:51:06.870 [INFO][69] felix/driver.go 60: Using internal (linux) dataplane driver.
bird: direct1: Reconfigured
bird: Mesh_192_168_231_41: Reconfigured
bird: Reconfigured
2021-09-21 17:51:06.872 [INFO][69] felix/driver.go 69: Kube-proxy in ipvs mode, enabling felix kube-proxy ipvs support.
2021-09-21 17:51:06.962 [INFO][69] felix/driver.go 148: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2021-09-21 17:51:06.963 [INFO][69] felix/int_dataplane.go 292: Creating internal dataplane driver. config=intdataplane.Config{Hostname:"node2", IPv6Enabled:false, RuleRendererOverride:rules.RuleRenderer(nil), IPIPMTU:0, VXLANMTU:0, VXLANPort:4789, MaxIPSetSize:1048576, IptablesBackend:"legacy", IPSetsRefreshInterval:10000000000, RouteRefreshInterval:90000000000, DeviceRouteSourceAddress:net.IP(nil), DeviceRouteProtocol:3, RemoveExternalRoutes:true, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckInterval:1000000000, IptablesInsertMode:"insert", IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeout:10000000000, IptablesLockProbeInterval:50000000, XDPRefreshInterval:90000000000, Wireguard:wireguard.Config{Enabled:false, ListeningPort:51820, FirewallMark:0, RoutingRulePriority:99, RoutingTableIndex:1, InterfaceName:"wireguard.cali", MTU:0}, NetlinkTimeout:10000000000, RulesConfig:rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc00083c2d0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc00083c3c0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x10000, IptablesMarkPass:0x20000, IptablesMarkScratch0:0x40000, IptablesMarkScratch1:0x80000, IptablesMarkEndpoint:0xfff00000, IptablesMarkNonCaliEndpoint:0x100000, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, KubeIPVSSupportEnabled:true, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, VXLANEnabled:false, VXLANPort:4789, VXLANVNI:4096, IPIPEnabled:true, IPIPTunnelAddress:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xa, 0xe9, 0x60, 0x0}, VXLANTunnelAddress:net.IP(nil), AllowVXLANPacketsFromWorkloads:false, AllowIPIPPacketsFromWorkloads:false, WireguardEnabled:false, WireguardInterfaceName:"wireguard.cali", IptablesLogPrefix:"calico-packet", EndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"tcp", Port:0x16}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x44}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"udp", Port:0x35}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x43}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, IptablesNATOutgoingInterfaceFilter:"", NATOutgoingAddress:net.IP(nil), BPFEnabled:false, ServiceLoopPrevention:"Drop"}, IfaceMonitorConfig:ifacemonitor.Config{InterfaceExcludes:[]*regexp.Regexp{(*regexp.Regexp)(0xc0004e5f40)}, ResyncInterval:90000000000}, StatusReportingInterval:0, ConfigChangedRestartCallback:(func())(0x211d940), FatalErrorRestartCallback:(func(error))(0x211da00), PostInSyncCallback:(func())(0x2104ca0), HealthAggregator:(*health.HealthAggregator)(0xc0007f0780), RouteTableManager:(*idalloc.IndexAllocator)(0xc000118088), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil), BPFEnabled:false, BPFDisableUnprivileged:true, BPFKubeProxyIptablesCleanupEnabled:true, BPFLogLevel:"off", BPFExtToServiceConnmark:0, BPFDataIfacePattern:(*regexp.Regexp)(0xc0004e5cc0), XDPEnabled:true, XDPAllowGeneric:false, BPFConntrackTimeouts:conntrack.Timeouts{CreationGracePeriod:10000000000, TCPPreEstablished:20000000000, TCPEstablished:3600000000000, TCPFinsSeen:30000000000, TCPResetSeen:40000000000, UDPLastSeen:60000000000, GenericIPLastSeen:600000000000, ICMPLastSeen:5000000000}, BPFCgroupV2:"", BPFConnTimeLBEnabled:true, BPFMapRepin:true, BPFNodePortDSREnabled:false, KubeProxyMinSyncPeriod:1000000000, KubeProxyEndpointSlicesEnabled:false, SidecarAccelerationEnabled:false, LookPathOverride:(func(string) (string, error))(nil), KubeClientSet:(*kubernetes.Clientset)(0xc0008c4420), FeatureDetectOverrides:map[string]string(nil), hostMTU:0, MTUIfacePattern:(*regexp.Regexp)(0xc000a92320)}
2021-09-21 17:51:06.964 [INFO][69] felix/rule_defs.go 345: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc00083c2d0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc00083c3c0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x10000, IptablesMarkPass:0x20000, IptablesMarkScratch0:0x40000, IptablesMarkScratch1:0x80000, IptablesMarkEndpoint:0xfff00000, IptablesMarkNonCaliEndpoint:0x100000, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, KubeIPVSSupportEnabled:true, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, VXLANEnabled:false, VXLANPort:4789, VXLANVNI:4096, IPIPEnabled:true, IPIPTunnelAddress:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xa, 0xe9, 0x60, 0x0}, VXLANTunnelAddress:net.IP(nil), AllowVXLANPacketsFromWorkloads:false, AllowIPIPPacketsFromWorkloads:false, WireguardEnabled:false, WireguardInterfaceName:"wireguard.cali", IptablesLogPrefix:"calico-packet", EndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"tcp", Port:0x16}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x44}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Net:"", Protocol:"udp", Port:0x35}, config.ProtoPort{Net:"", Protocol:"udp", Port:0x43}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0xb3}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x94c}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1561}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x192b}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Net:"", Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, IptablesNATOutgoingInterfaceFilter:"", NATOutgoingAddress:net.IP(nil), BPFEnabled:false, ServiceLoopPrevention:"Drop"}
2021-09-21 17:51:07.161 [INFO][70] confd/resource.go 277: Target config /etc/calico/confd/config/bird.cfg has been updated
2021-09-21 17:51:06.967 [INFO][69] felix/rule_defs.go 358: Workload to host packets will be returned to INPUT chain.
2021-09-21 17:51:07.162 [INFO][69] felix/rule_defs.go 369: filter table allowed packets will be accepted immediately.
2021-09-21 17:51:07.162 [INFO][69] felix/rule_defs.go 377: mangle table allowed packets will be accepted immediately.
2021-09-21 17:51:07.162 [INFO][69] felix/rule_defs.go 385: Packets to unknown service IPs will be dropped
2021-09-21 17:51:07.168 [INFO][69] felix/int_dataplane.go 930: Determined pod MTU mtu=1480
2021-09-21 17:51:07.262 [INFO][69] felix/iface_monitor.go 74: configured to periodically rescan interfaces. interval=1m30s
2021-09-21 17:51:07.263 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"ip6tables-legacy-save", "ip6tables-save"} command="ip6tables-legacy-save" ipVersion=0x6 saveOrRestore="save"
2021-09-21 17:51:07.263 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
bird: device1: Initializing
bird: direct1: Initializing
bird: device1: Starting
bird: device1: Connected to table master
bird: device1: State changed to feed
bird: direct1: Starting
bird: direct1: Connected to table master
bird: direct1: State changed to feed
bird: Graceful restart started
bird: Graceful restart done
bird: Started
bird: device1: State changed to up
bird: direct1: State changed to up
2021-09-21 17:51:07.771 [INFO][69] felix/health.go 196: Overall health status changed newStatus=&health.HealthReport{Live:true, Ready:true}
2021-09-21 17:51:08.470 [INFO][69] felix/feature_detect.go 153: Updating detected iptables features features=iptables.Features{SNATFullyRandom:false, MASQFullyRandom:false, RestoreSupportsLock:true, ChecksumOffloadBroken:true} iptablesVersion=1.8.4 kernelVersion=3.10.0-1160
2021-09-21 17:51:08.471 [INFO][69] felix/table.go 334: Calculated old-insert detection regex. pattern="(?:-j|--jump) cali-|(?:-j|--jump) califw-|(?:-j|--jump) calitw-|(?:-j|--jump) califh-|(?:-j|--jump) calith-|(?:-j|--jump) calipi-|(?:-j|--jump) calipo-|(?:-j|--jump) felix-"
2021-09-21 17:51:08.563 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2021-09-21 17:51:08.564 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2021-09-21 17:51:08.564 [INFO][69] felix/table.go 334: Calculated old-insert detection regex. pattern="(?:-j|--jump) cali-|(?:-j|--jump) califw-|(?:-j|--jump) calitw-|(?:-j|--jump) califh-|(?:-j|--jump) calith-|(?:-j|--jump) calipi-|(?:-j|--jump) calipo-|(?:-j|--jump) felix-|-A POSTROUTING .* felix-masq-ipam-pools .*|-A POSTROUTING -o tunl0 -m addrtype ! --src-type LOCAL --limit-iface-out -m addrtype --src-type LOCAL -j MASQUERADE"
2021-09-21 17:51:08.564 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2021-09-21 17:51:08.565 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2021-09-21 17:51:08.565 [INFO][69] felix/table.go 334: Calculated old-insert detection regex. pattern="(?:-j|--jump) cali-|(?:-j|--jump) califw-|(?:-j|--jump) calitw-|(?:-j|--jump) califh-|(?:-j|--jump) calith-|(?:-j|--jump) calipi-|(?:-j|--jump) calipo-|(?:-j|--jump) felix-"
2021-09-21 17:51:08.565 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2021-09-21 17:51:08.565 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2021-09-21 17:51:08.565 [INFO][69] felix/table.go 334: Calculated old-insert detection regex. pattern="(?:-j|--jump) cali-|(?:-j|--jump) califw-|(?:-j|--jump) calitw-|(?:-j|--jump) califh-|(?:-j|--jump) calith-|(?:-j|--jump) calipi-|(?:-j|--jump) calipo-|(?:-j|--jump) felix-"
2021-09-21 17:51:08.566 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2021-09-21 17:51:08.566 [INFO][69] felix/feature_detect.go 275: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2021-09-21 17:51:08.662 [WARNING][69] felix/int_dataplane.go 458: Can't enable XDP acceleration. error=kernel is too old (have: 3.10.0-1160 but want at least: 4.16.0)
2021-09-21 17:51:08.786 [INFO][69] felix/int_dataplane.go 531: Failed to remove BPF connect-time load balancer, ignoring. error=failed to set-up cgroupv2: no such device
2021-09-21 17:51:09.369 [INFO][69] felix/route_table.go 249: Calculated interface name regexp regex="^cali.*"
2021-09-21 17:51:09.467 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2021-09-21 17:51:09.468 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2021-09-21 17:51:09.468 [INFO][69] felix/route_table.go 249: Calculated interface name regexp regex="^wireguard.cali$"
2021-09-21 17:51:09.468 [INFO][69] felix/int_dataplane.go 834: Registering to report health.
2021-09-21 17:51:09.764 [INFO][69] felix/int_dataplane.go 1623: attempted to modprobe nf_conntrack_proto_sctp error=exit status 1 output=""
2021-09-21 17:51:09.765 [INFO][69] felix/int_dataplane.go 1625: Making sure IPv4 forwarding is enabled.
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-host-endpoint"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-to-host-endpoint"
2021-09-21 17:51:09.766 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-PREROUTING"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-OUTPUT"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-hep-forward"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-wl-dispatch"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-to-wl-dispatch"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-to-hep-forward"
2021-09-21 17:51:09.767 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-cidr-block"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-forward-check"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-wl-to-host"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-host-endpoint"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-forward-check" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-set-endpoint-mark"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-forward-endpoint-mark"
2021-09-21 17:51:09.768 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-to-host-endpoint"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-forward-endpoint-mark" ipVersion=0x4 table="filter"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-endpoint-mark"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-FORWARD"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-INPUT"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-OUTPUT"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-fip-dnat"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-fip-snat"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-nat-outgoing"
2021-09-21 17:51:09.769 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2021-09-21 17:51:09.770 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-PREROUTING"
2021-09-21 17:51:09.770 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-POSTROUTING"
2021-09-21 17:51:09.770 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-OUTPUT"
2021-09-21 17:51:09.770 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2021-09-21 17:51:10.063 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="mangle"
2021-09-21 17:51:10.063 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2021-09-21 17:51:10.064 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-from-host-endpoint"
2021-09-21 17:51:10.064 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="mangle"
2021-09-21 17:51:10.064 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-to-host-endpoint"
2021-09-21 17:51:10.064 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-PREROUTING"
2021-09-21 17:51:10.162 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-POSTROUTING"
2021-09-21 17:51:10.163 [INFO][69] felix/int_dataplane.go 1089: IPIP enabled, starting thread to keep tunnel configuration in sync.
2021-09-21 17:51:10.163 [INFO][69] felix/daemon.go 400: Connect to the dataplane driver.
2021-09-21 17:51:10.164 [INFO][69] felix/daemon.go 478: using resource updates where applicable
2021-09-21 17:51:10.164 [INFO][69] felix/daemon.go 481: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc00090ad80), (*watchersyncer.watcherCache)(0xc00090ae00), (*watchersyncer.watcherCache)(0xc00090ae80), (*watchersyncer.watcherCache)(0xc00090af00), (*watchersyncer.watcherCache)(0xc00090af80), (*watchersyncer.watcherCache)(0xc00090b000), (*watchersyncer.watcherCache)(0xc00090b080), (*watchersyncer.watcherCache)(0xc00090b100), (*watchersyncer.watcherCache)(0xc00090b180), (*watchersyncer.watcherCache)(0xc00090b200), (*watchersyncer.watcherCache)(0xc00090b280), (*watchersyncer.watcherCache)(0xc00090b300), (*watchersyncer.watcherCache)(0xc00090b380), (*watchersyncer.watcherCache)(0xc00090b400)}, results:(chan interface {})(0xc000290900), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc000296740), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2021-09-21 17:51:10.164 [INFO][69] felix/daemon.go 485: Starting the datastore Syncer
2021-09-21 17:51:10.164 [INFO][69] felix/watchersyncer.go 89: Start called
2021-09-21 17:51:10.165 [INFO][69] felix/calc_graph.go 114: Creating calculation graph, filtered to hostname node2
2021-09-21 17:51:10.165 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1aa7bc0)
2021-09-21 17:51:10.165 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1aa7bc0)
2021-09-21 17:51:10.165 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1aa7cc0)
2021-09-21 17:51:10.165 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1aa7cc0)
2021-09-21 17:51:10.165 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x1aa7a60)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x19e6940)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x19e6940)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x19e6940)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x19e6940)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x19e6940)
2021-09-21 17:51:10.166 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1aa8280)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1aa8280)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1aa8280)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x1aa7e60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x1aa7e60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WireguardKey: (dispatcher.UpdateHandler)(0x1aa7e60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ResourceKey: (dispatcher.UpdateHandler)(0x1aa7e60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x1aa7d60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x1aa7d60)
2021-09-21 17:51:10.167 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x1aa7d60)
2021-09-21 17:51:10.168 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x1aa8400)
2021-09-21 17:51:10.168 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x1aa84a0)
2021-09-21 17:51:10.265 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1aa84a0)
2021-09-21 17:51:10.261 [INFO][69] felix/int_dataplane.go 1401: Started internal iptables dataplane driver loop
2021-09-21 17:51:10.265 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1aa84a0)
2021-09-21 17:51:10.265 [INFO][69] felix/int_dataplane.go 1411: Will refresh IP sets on timer interval=1m30s
2021-09-21 17:51:10.265 [INFO][69] felix/dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x1aa84a0)
2021-09-21 17:51:10.265 [INFO][69] felix/int_dataplane.go 1421: Will refresh routes on timer interval=1m30s
2021-09-21 17:51:10.262 [INFO][69] felix/iface_monitor.go 100: Interface monitoring thread started.
2021-09-21 17:51:10.265 [INFO][69] felix/async_calc_graph.go 255: Starting AsyncCalcGraph
2021-09-21 17:51:10.265 [INFO][69] felix/daemon.go 592: Started the processing graph
2021-09-21 17:51:10.266 [INFO][69] felix/iface_monitor.go 118: Subscribed to netlink updates.
2021-09-21 17:51:10.266 [INFO][69] felix/async_calc_graph.go 137: AsyncCalcGraph running
2021-09-21 17:51:10.266 [INFO][69] felix/int_dataplane.go 1004: Linux interface state changed. ifIndex=1 ifaceName="lo" state="up"
2021-09-21 17:51:10.263 [INFO][69] felix/int_dataplane.go 1854: Started internal status report thread
2021-09-21 17:51:10.267 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.0":set.empty{}, "127.0.0.1":set.empty{}, "::1":set.empty{}, "fe80::8f7f:1342:39ed:5c9c":set.empty{}, "fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="lo"
2021-09-21 17:51:10.267 [INFO][69] felix/int_dataplane.go 1004: Linux interface state changed. ifIndex=2 ifaceName="ens160" state="up"
2021-09-21 17:51:10.268 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"192.168.231.42":set.empty{}} ifaceName="ens160"
2021-09-21 17:51:10.366 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"192.168.122.1":set.empty{}} ifaceName="virbr0"
2021-09-21 17:51:10.368 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="virbr0-nic"
2021-09-21 17:51:10.369 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"172.17.0.1":set.empty{}} ifaceName="docker0"
2021-09-21 17:51:10.369 [INFO][69] felix/int_dataplane.go 1004: Linux interface state changed. ifIndex=16 ifaceName="tunl0" state="up"
2021-09-21 17:51:10.370 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"10.233.96.0":set.empty{}} ifaceName="tunl0"
2021-09-21 17:51:10.372 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{"169.254.25.10":set.empty{}} ifaceName="nodelocaldns"
2021-09-21 17:51:10.267 [INFO][69] felix/int_dataplane.go 1856: Process status reports disabled
2021-09-21 17:51:10.463 [INFO][69] felix/daemon.go 689: No driver process to monitor
2021-09-21 17:51:10.470 [INFO][69] felix/int_dataplane.go 1462: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up", Index:1}
2021-09-21 17:51:10.471 [INFO][69] felix/daemon.go 970: Reading from dataplane driver pipe...
2021-09-21 17:51:10.372 [INFO][69] felix/int_dataplane.go 1004: Linux interface state changed. ifIndex=25 ifaceName="cali07d7014d27b" state="up"
2021-09-21 17:51:10.472 [INFO][69] felix/int_dataplane.go 1039: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali07d7014d27b"
2021-09-21 17:51:10.470 [INFO][69] felix/int_dataplane.go 1462: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens160", State:"up", Index:2}
2021-09-21 17:51:10.472 [INFO][69] felix/int_dataplane.go 1462: Received interface update msg=&intdataplane.ifaceUpdate{Name:"tunl0", State:"up", Index:16}
2021-09-21 17:51:10.264 [INFO][69] felix/ipip_mgr.go 85: IPIP thread started.
2021-09-21 17:51:10.264 [INFO][69] felix/watchersyncer.go 127: Sending status update Status=wait-for-ready
2021-09-21 17:51:10.563 [INFO][69] felix/watchersyncer.go 147: Starting main event processing loop
2021-09-21 17:51:10.564 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/ipam/v2/assignment/"
2021-09-21 17:51:10.472 [INFO][69] felix/int_dataplane.go 1462: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali07d7014d27b", State:"up", Index:25}
2021-09-21 17:51:10.566 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2021-09-21 17:51:10.566 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"BPFEnabled" value:"false" > config:<key:"BPFExternalServiceMode" value:"Tunnel" > config:<key:"CalicoVersion" value:"v3.19.2" > config:<key:"ChainInsertMode" value:"Insert" > config:<key:"ClusterGUID" value:"77b463ba17864605b6c2804c0bcc305a" > config:<key:"ClusterType" value:"kubespray,bgp,kubeadm,kdd,k8s" > config:<key:"DatastoreType" value:"kubernetes" > config:<key:"DefaultEndpointToHostAction" value:"RETURN" > config:<key:"FelixHostname" value:"node2" > config:<key:"HealthEnabled" value:"true" > config:<key:"HealthHost" value:"localhost" > config:<key:"IpInIpEnabled" value:"true" > config:<key:"IpInIpTunnelAddr" value:"10.233.96.0" > config:<key:"IptablesBackend" value:"Legacy" > config:<key:"IptablesLockTimeoutSecs" value:"10" > config:<key:"Ipv6Support" value:"False" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"PrometheusGoMetricsEnabled" value:"True" > config:<key:"PrometheusMetricsEnabled" value:"False" > config:<key:"PrometheusMetricsPort" value:"9091" > config:<key:"PrometheusProcessMetricsEnabled" value:"True" > config:<key:"ReportingIntervalSecs" value:"0" > config:<key:"UsageReportingEnabled" value:"False" > config:<key:"WireguardEnabled" value:"false" > config:<key:"ignorelooserpf" value:"False" > 
2021-09-21 17:51:10.567 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2021-09-21 17:51:10.566 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.0":set.empty{}, "127.0.0.1":set.empty{}, "::1":set.empty{}, "fe80::8f7f:1342:39ed:5c9c":set.empty{}, "fe80::ecee:eeff:feee:eeee":set.empty{}}}
2021-09-21 17:51:10.567 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.0":set.empty{}, "127.0.0.1":set.empty{}, "::1":set.empty{}, "fe80::8f7f:1342:39ed:5c9c":set.empty{}, "fe80::ecee:eeff:feee:eeee":set.empty{}}}
2021-09-21 17:51:10.567 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.567 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens160", Addrs:set.mapSet{"192.168.231.42":set.empty{}}}
2021-09-21 17:51:10.567 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens160", Addrs:set.mapSet{"192.168.231.42":set.empty{}}}
2021-09-21 17:51:10.567 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2021-09-21 17:51:10.567 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.567 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"virbr0", Addrs:set.mapSet{"192.168.122.1":set.empty{}}}
2021-09-21 17:51:10.568 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"virbr0", Addrs:set.mapSet{"192.168.122.1":set.empty{}}}
2021-09-21 17:51:10.568 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.568 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2021-09-21 17:51:10.568 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"virbr0-nic", Addrs:set.mapSet{}}
2021-09-21 17:51:10.568 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2021-09-21 17:51:10.569 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:51:10.570 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2021-09-21 17:51:10.571 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2021-09-21 17:51:10.568 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"virbr0-nic", Addrs:set.mapSet{}}
2021-09-21 17:51:10.662 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/networksets"
2021-09-21 17:51:10.663 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.663 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"docker0", Addrs:set.mapSet{"172.17.0.1":set.empty{}}}
2021-09-21 17:51:10.663 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"docker0", Addrs:set.mapSet{"172.17.0.1":set.empty{}}}
2021-09-21 17:51:10.663 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.663 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{"10.233.96.0":set.empty{}}}
2021-09-21 17:51:10.664 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{"10.233.96.0":set.empty{}}}
2021-09-21 17:51:10.664 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2021-09-21 17:51:10.664 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.664 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"nodelocaldns", Addrs:set.mapSet{"169.254.25.10":set.empty{}}}
2021-09-21 17:51:10.664 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"nodelocaldns", Addrs:set.mapSet{"169.254.25.10":set.empty{}}}
2021-09-21 17:51:10.664 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2021-09-21 17:51:10.664 [INFO][69] felix/int_dataplane.go 1480: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali07d7014d27b", Addrs:set.mapSet{}}
2021-09-21 17:51:10.664 [INFO][69] felix/hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali07d7014d27b", Addrs:set.mapSet{}}
2021-09-21 17:51:10.664 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/bgpconfigurations"
2021-09-21 17:51:10.662 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2021-09-21 17:51:10.665 [INFO][69] felix/watchercache.go 174: Full resync is required ListRoot="/calico/resources/v3/projectcalico.org/kubernetesnetworkpolicies"
2021-09-21 17:51:11.066 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2021-09-21 17:51:11.163 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/ipam/v2/assignment/"
2021-09-21 17:51:11.164 [INFO][69] felix/watchersyncer.go 127: Sending status update Status=resync
2021-09-21 17:51:11.163 [WARNING][69] felix/health.go 188: Reporter is not ready. name="int_dataplane"
2021-09-21 17:51:11.164 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.164 [WARNING][69] felix/health.go 188: Reporter is not ready. name="async_calc_graph"
2021-09-21 17:51:11.164 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.164 [INFO][69] felix/health.go 196: Overall health status changed newStatus=&health.HealthReport{Live:true, Ready:false}
2021-09-21 17:51:11.165 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 77b463ba17864605b6c2804c0bcc305a 1355 <nil> 0s} 1}
2021-09-21 17:51:11.166 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) kubespray,bgp,kubeadm,kdd,k8s 1355 <nil> 0s} 1}
2021-09-21 17:51:11.166 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.19.2 1355 <nil> 0s} 1}
2021-09-21 17:51:11.365 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 855 <nil> 0s} 1}
2021-09-21 17:51:11.366 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2021-09-21 17:51:11.368 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.664 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2021-09-21 17:51:11.667 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.668 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2021-09-21 17:51:11.668 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.669 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networksets"
2021-09-21 17:51:11.670 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.768 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=IpInIpEnabled) true 855 <nil> 0s} 1}
2021-09-21 17:51:11.862 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 855 <nil> 0s} 1}
2021-09-21 17:51:11.869 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/bgpconfigurations"
2021-09-21 17:51:11.964 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.967 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2021-09-21 17:51:11.968 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:11.969 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2021-09-21 17:51:12.073 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:12.073 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2021-09-21 17:51:12.073 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:12.076 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2021-09-21 17:51:11.862 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=BPFEnabled) false 855 <nil> 0s} 1}
2021-09-21 17:51:12.163 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=BPFExternalServiceMode) Tunnel 855 <nil> 0s} 1}
2021-09-21 17:51:12.163 [INFO][69] felix/config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=WireguardEnabled) false 855 <nil> 0s} 1}
2021-09-21 17:51:12.164 [INFO][69] felix/config_batcher.go 61: Host config update for this host: {{HostConfig(node=node2,name=IpInIpTunnelAddr) 10.233.96.0 949471 <nil> 0s} 1}
2021-09-21 17:51:12.164 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:12.165 [INFO][69] felix/int_dataplane.go 1447: Received *proto.GlobalBGPConfigUpdate update from calculation graph msg=
2021-09-21 17:51:12.165 [INFO][69] felix/int_dataplane.go 1447: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"node1" ipv4_addr:"192.168.231.41" 
2021-09-21 17:51:12.166 [INFO][69] felix/int_dataplane.go 1447: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"node2" ipv4_addr:"192.168.231.42" 
2021-09-21 17:51:12.166 [INFO][69] felix/int_dataplane.go 1447: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"10.233.64.0-18" pool:<cidr:"10.233.64.0/18" masquerade:true > 
2021-09-21 17:51:12.363 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/kubernetesnetworkpolicies"
2021-09-21 17:51:12.363 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:12.566 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"calico-node" > labels:<key:"projectcalico.org/name" value:"calico-node" > 
2021-09-21 17:51:12.662 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2021-09-21 17:51:12.663 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:12.868 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"coredns" > labels:<key:"addonmanager.kubernetes.io/mode" value:"Reconcile" > labels:<key:"projectcalico.org/name" value:"coredns" > 
2021-09-21 17:51:12.868 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"cronjob-controller" > labels:<key:"projectcalico.org/name" value:"cronjob-controller" > 
2021-09-21 17:51:12.869 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"ephemeral-volume-controller" > labels:<key:"projectcalico.org/name" value:"ephemeral-volume-controller" > 
2021-09-21 17:51:12.869 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"bootstrap-signer" > labels:<key:"projectcalico.org/name" value:"bootstrap-signer" > 
2021-09-21 17:51:12.870 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"replication-controller" > labels:<key:"projectcalico.org/name" value:"replication-controller" > 
2021-09-21 17:51:12.870 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"default" > labels:<key:"projectcalico.org/name" value:"default" > 
2021-09-21 17:51:13.263 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-public" name:"default" > labels:<key:"projectcalico.org/name" value:"default" > 
2021-09-21 17:51:13.263 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"clusterrole-aggregation-controller" > labels:<key:"projectcalico.org/name" value:"clusterrole-aggregation-controller" > 
2021-09-21 17:51:13.263 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"daemon-set-controller" > labels:<key:"projectcalico.org/name" value:"daemon-set-controller" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"dns-autoscaler" > labels:<key:"addonmanager.kubernetes.io/mode" value:"Reconcile" > labels:<key:"projectcalico.org/name" value:"dns-autoscaler" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"endpoint-controller" > labels:<key:"projectcalico.org/name" value:"endpoint-controller" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"endpointslicemirroring-controller" > labels:<key:"projectcalico.org/name" value:"endpointslicemirroring-controller" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-node-lease" name:"default" > labels:<key:"projectcalico.org/name" value:"default" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"deployment-controller" > labels:<key:"projectcalico.org/name" value:"deployment-controller" > 
2021-09-21 17:51:13.264 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"disruption-controller" > labels:<key:"projectcalico.org/name" value:"disruption-controller" > 
2021-09-21 17:51:13.265 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"job-controller" > labels:<key:"projectcalico.org/name" value:"job-controller" > 
2021-09-21 17:51:13.265 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"namespace-controller" > labels:<key:"projectcalico.org/name" value:"namespace-controller" > 
2021-09-21 17:51:13.265 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"node-controller" > labels:<key:"projectcalico.org/name" value:"node-controller" > 
2021-09-21 17:51:13.265 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"nodelocaldns" > labels:<key:"addonmanager.kubernetes.io/mode" value:"Reconcile" > labels:<key:"projectcalico.org/name" value:"nodelocaldns" > 
2021-09-21 17:51:13.265 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"persistent-volume-binder" > labels:<key:"projectcalico.org/name" value:"persistent-volume-binder" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"attachdetach-controller" > labels:<key:"projectcalico.org/name" value:"attachdetach-controller" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"pvc-protection-controller" > labels:<key:"projectcalico.org/name" value:"pvc-protection-controller" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"replicaset-controller" > labels:<key:"projectcalico.org/name" value:"replicaset-controller" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"horizontal-pod-autoscaler" > labels:<key:"projectcalico.org/name" value:"horizontal-pod-autoscaler" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"expand-controller" > labels:<key:"projectcalico.org/name" value:"expand-controller" > 
2021-09-21 17:51:13.266 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"endpointslice-controller" > labels:<key:"projectcalico.org/name" value:"endpointslice-controller" > 
2021-09-21 17:51:13.267 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"generic-garbage-collector" > labels:<key:"projectcalico.org/name" value:"generic-garbage-collector" > 
2021-09-21 17:51:13.267 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"default" name:"default" > labels:<key:"projectcalico.org/name" value:"default" > 
2021-09-21 17:51:13.267 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"certificate-controller" > labels:<key:"projectcalico.org/name" value:"certificate-controller" > 
2021-09-21 17:51:13.267 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"kube-proxy" > labels:<key:"projectcalico.org/name" value:"kube-proxy" > 
2021-09-21 17:51:13.267 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"pod-garbage-collector" > labels:<key:"projectcalico.org/name" value:"pod-garbage-collector" > 
2021-09-21 17:51:13.268 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"pv-protection-controller" > labels:<key:"projectcalico.org/name" value:"pv-protection-controller" > 
2021-09-21 17:51:13.268 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"calico-kube-controllers" > labels:<key:"projectcalico.org/name" value:"calico-kube-controllers" > 
2021-09-21 17:51:13.363 [WARNING][69] felix/health.go 188: Reporter is not ready. name="int_dataplane"
2021-09-21 17:51:13.363 [WARNING][69] felix/health.go 188: Reporter is not ready. name="async_calc_graph"
2021-09-21 17:51:13.364 [WARNING][69] felix/health.go 154: Health: not ready
2021-09-21 17:51:13.268 [INFO][69] felix/int_dataplane.go 1447: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"default" > labels:<key:"kubernetes.io/metadata.name" value:"default" > labels:<key:"projectcalico.org/name" value:"default" > 
2021-09-21 17:51:13.562 [INFO][69] felix/int_dataplane.go 1447: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-node-lease" > labels:<key:"kubernetes.io/metadata.name" value:"kube-node-lease" > labels:<key:"projectcalico.org/name" value:"kube-node-lease" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-public" > labels:<key:"kubernetes.io/metadata.name" value:"kube-public" > labels:<key:"projectcalico.org/name" value:"kube-public" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-system" > labels:<key:"kubernetes.io/metadata.name" value:"kube-system" > labels:<key:"projectcalico.org/name" value:"kube-system" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"token-cleaner" > labels:<key:"projectcalico.org/name" value:"token-cleaner" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"ttl-after-finished-controller" > labels:<key:"projectcalico.org/name" value:"ttl-after-finished-controller" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"ttl-controller" > labels:<key:"projectcalico.org/name" value:"ttl-controller" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"resourcequota-controller" > labels:<key:"projectcalico.org/name" value:"resourcequota-controller" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"root-ca-cert-publisher" > labels:<key:"projectcalico.org/name" value:"root-ca-cert-publisher" > 
2021-09-21 17:51:13.563 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"service-account-controller" > labels:<key:"projectcalico.org/name" value:"service-account-controller" > 
2021-09-21 17:51:13.564 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"service-controller" > labels:<key:"projectcalico.org/name" value:"service-controller" > 
2021-09-21 17:51:13.564 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"statefulset-controller" > labels:<key:"projectcalico.org/name" value:"statefulset-controller" > 
2021-09-21 17:51:13.666 [INFO][69] felix/watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2021-09-21 17:51:13.667 [INFO][69] felix/watchersyncer.go 209: Received InSync event from one of the watcher caches
2021-09-21 17:51:13.667 [INFO][69] felix/watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2021-09-21 17:51:13.667 [INFO][69] felix/watchersyncer.go 127: Sending status update Status=in-sync
2021-09-21 17:51:13.762 [INFO][69] felix/calc_graph.go 413: Local endpoint updated id=WorkloadEndpoint(node=node2, orchestrator=k8s, workload=kube-system/coredns-8474476ff8-b6lqz, name=eth0)
2021-09-21 17:51:13.764 [INFO][69] felix/config_batcher.go 102: Datamodel in sync, flushing config update
2021-09-21 17:51:13.764 [INFO][69] felix/config_batcher.go 112: Sending config update global: map[BPFEnabled:false BPFExternalServiceMode:Tunnel CalicoVersion:v3.19.2 ClusterGUID:77b463ba17864605b6c2804c0bcc305a ClusterType:kubespray,bgp,kubeadm,kdd,k8s IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0 WireguardEnabled:false], host: map[IpInIpTunnelAddr:10.233.96.0].
2021-09-21 17:51:13.764 [INFO][69] felix/async_calc_graph.go 166: First time we've been in sync
2021-09-21 17:51:13.765 [INFO][69] felix/health.go 133: Health of component changed lastReport=health.HealthReport{Live:true, Ready:false} name="async_calc_graph" newReport=&health.HealthReport{Live:true, Ready:true}
2021-09-21 17:51:13.765 [INFO][69] felix/event_sequencer.go 234: Possible config update. global=map[string]string{"BPFEnabled":"false", "BPFExternalServiceMode":"Tunnel", "CalicoVersion":"v3.19.2", "ClusterGUID":"77b463ba17864605b6c2804c0bcc305a", "ClusterType":"kubespray,bgp,kubeadm,kdd,k8s", "IpInIpEnabled":"true", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "WireguardEnabled":"false"} host=map[string]string{"IpInIpTunnelAddr":"10.233.96.0"}
2021-09-21 17:51:13.766 [INFO][69] felix/config_params.go 343: Merging in config from datastore (global): map[BPFEnabled:false BPFExternalServiceMode:Tunnel CalicoVersion:v3.19.2 ClusterGUID:77b463ba17864605b6c2804c0bcc305a ClusterType:kubespray,bgp,kubeadm,kdd,k8s IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0 WireguardEnabled:false]
2021-09-21 17:51:13.870 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:13.871 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:13.871 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:13.964 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:13.965 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:13.764 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"ksa.kube-system.coredns" > profile:<> 
2021-09-21 17:51:14.064 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pri-_u2Tn2rSoAPffvE7JO6" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.064 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pro-_u2Tn2rSoAPffvE7JO6" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.065 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pro-_u2Tn2rSoAPffvE7JO6" ipVersion=0x4 table="mangle"
2021-09-21 17:51:14.065 [INFO][69] felix/int_dataplane.go 1447: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"kns.kube-system" > profile:<inbound_rules:<action:"allow" rule_id:"YlN-KJA93B7Fe2ih" > outbound_rules:<action:"allow" rule_id:"GUM3x2IgYhIM5cBY" > > 
2021-09-21 17:51:14.065 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pri-kns.kube-system" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.066 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pro-kns.kube-system" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.066 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-pro-kns.kube-system" ipVersion=0x4 table="mangle"
2021-09-21 17:51:13.966 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:14.069 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:14.070 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:14.070 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:14.070 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:14.070 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:14.264 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:14.264 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:14.264 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:14.264 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:14.264 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:14.265 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityFile: None (from config file)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityFile:  (from config file)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 432: Parsing value for LogSeveritySys: None (from config file)
2021-09-21 17:51:14.266 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.267 [INFO][69] felix/config_params.go 468: Parsed value for LogSeveritySys:  (from config file)
2021-09-21 17:51:14.269 [INFO][69] felix/config_params.go 432: Parsing value for MetadataAddr: None (from config file)
2021-09-21 17:51:14.269 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.269 [INFO][69] felix/config_params.go 468: Parsed value for MetadataAddr:  (from config file)
2021-09-21 17:51:14.269 [INFO][69] felix/config_params.go 432: Parsing value for LogFilePath: None (from config file)
2021-09-21 17:51:14.366 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.366 [INFO][69] felix/config_params.go 468: Parsed value for LogFilePath:  (from config file)
2021-09-21 17:51:14.366 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:14.366 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: Info (from datastore (global))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 471: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 432: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 468: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 432: Parsing value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:14.367 [INFO][69] felix/config_params.go 468: Parsed value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 432: Parsing value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 468: Parsed value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 432: Parsing value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 468: Parsed value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 432: Parsing value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:14.368 [INFO][69] felix/config_params.go 468: Parsed value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 432: Parsing value for BPFExternalServiceMode: Tunnel (from datastore (global))
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 468: Parsed value for BPFExternalServiceMode: tunnel (from datastore (global))
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 432: Parsing value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 468: Parsed value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 343: Merging in config from datastore (per-host): map[IpInIpTunnelAddr:10.233.96.0]
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 432: Parsing value for IptablesBackend: Legacy (from environment variable)
2021-09-21 17:51:14.369 [INFO][69] felix/config_params.go 468: Parsed value for IptablesBackend: legacy (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 432: Parsing value for Ipv6Support: False (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 468: Parsed value for Ipv6Support: false (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 432: Parsing value for IptablesLockTimeoutSecs: 10 (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 468: Parsed value for IptablesLockTimeoutSecs: 10s (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusGoMetricsEnabled: True (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusGoMetricsEnabled: true (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsPort: 9091 (from environment variable)
2021-09-21 17:51:14.370 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: info (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 432: Parsing value for UsageReportingEnabled: False (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 468: Parsed value for UsageReportingEnabled: false (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 432: Parsing value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 468: Parsed value for FelixHostname: node2 (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 432: Parsing value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 468: Parsed value for HealthHost: localhost (from environment variable)
2021-09-21 17:51:14.371 [INFO][69] felix/config_params.go 432: Parsing value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 468: Parsed value for HealthEnabled: true (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 432: Parsing value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 468: Parsed value for DefaultEndpointToHostAction: RETURN (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusMetricsEnabled: False (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusMetricsEnabled: false (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 432: Parsing value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 468: Parsed value for DatastoreType: kubernetes (from environment variable)
2021-09-21 17:51:14.372 [INFO][69] felix/config_params.go 432: Parsing value for PrometheusProcessMetricsEnabled: True (from environment variable)
2021-09-21 17:51:14.373 [INFO][69] felix/config_params.go 468: Parsed value for PrometheusProcessMetricsEnabled: true (from environment variable)
2021-09-21 17:51:14.373 [INFO][69] felix/config_params.go 420: Ignoring unknown config param. raw name="ignorelooserpf"
2021-09-21 17:51:14.373 [INFO][69] felix/config_params.go 432: Parsing value for ChainInsertMode: Insert (from environment variable)
2021-09-21 17:51:14.373 [INFO][69] felix/config_params.go 468: Parsed value for ChainInsertMode: insert (from environment variable)
2021-09-21 17:51:14.373 [INFO][69] felix/config_params.go 432: Parsing value for MetadataAddr: None (from config file)
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 468: Parsed value for MetadataAddr:  (from config file)
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 432: Parsing value for LogFilePath: None (from config file)
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 468: Parsed value for LogFilePath:  (from config file)
2021-09-21 17:51:14.462 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityFile: None (from config file)
2021-09-21 17:51:14.463 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.463 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityFile:  (from config file)
2021-09-21 17:51:14.463 [INFO][69] felix/config_params.go 432: Parsing value for LogSeveritySys: None (from config file)
2021-09-21 17:51:14.463 [INFO][69] felix/config_params.go 449: Value set to 'none', replacing with zero-value: "".
2021-09-21 17:51:14.463 [INFO][69] felix/config_params.go 468: Parsed value for LogSeveritySys:  (from config file)
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpTunnelAddr: 10.233.96.0 (from datastore (per-host))
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 432: Parsing value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 468: Parsed value for CalicoVersion: v3.19.2 (from datastore (global))
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 432: Parsing value for BPFExternalServiceMode: Tunnel (from datastore (global))
2021-09-21 17:51:14.464 [INFO][69] felix/config_params.go 468: Parsed value for BPFExternalServiceMode: tunnel (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 432: Parsing value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 468: Parsed value for WireguardEnabled: false (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 432: Parsing value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 468: Parsed value for IpInIpEnabled: true (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 432: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 468: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2021-09-21 17:51:14.465 [INFO][69] felix/config_params.go 432: Parsing value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 468: Parsed value for ClusterGUID: 77b463ba17864605b6c2804c0bcc305a (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 432: Parsing value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 468: Parsed value for BPFEnabled: false (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 432: Parsing value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 468: Parsed value for ClusterType: kubespray,bgp,kubeadm,kdd,k8s (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 432: Parsing value for LogSeverityScreen: Info (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 468: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2021-09-21 17:51:14.466 [INFO][69] felix/config_params.go 471: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2021-09-21 17:51:14.467 [INFO][69] felix/async_calc_graph.go 220: First flush after becoming in sync, sending InSync message.
2021-09-21 17:51:14.467 [INFO][69] felix/daemon.go 1137: Datastore now in sync.
2021-09-21 17:51:14.467 [INFO][69] felix/daemon.go 1139: Datastore in sync for first time, sending message to status reporter.
2021-09-21 17:51:14.468 [INFO][69] felix/int_dataplane.go 1447: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-8474476ff8-b6lqz" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali07d7014d27b" profile_ids:"kns.kube-system" profile_ids:"ksa.kube-system.coredns" ipv4_nets:"10.233.96.1/32" > 
2021-09-21 17:51:14.469 [INFO][69] felix/int_dataplane.go 1447: Received *proto.InSync update from calculation graph msg=
2021-09-21 17:51:14.469 [INFO][69] felix/int_dataplane.go 1455: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=12.205347207s
2021-09-21 17:51:14.470 [INFO][69] felix/endpoint_mgr.go 365: Workload interface came up, marking for reconfiguration. ifaceName="cali07d7014d27b"
2021-09-21 17:51:14.470 [INFO][69] felix/endpoint_mgr.go 583: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"}
2021-09-21 17:51:14.471 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-tw-cali07d7014d27b" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.471 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-pri-kns.kube-system"
2021-09-21 17:51:14.471 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-pri-_u2Tn2rSoAPffvE7JO6"
2021-09-21 17:51:14.471 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-fw-cali07d7014d27b" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.663 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-pro-kns.kube-system"
2021-09-21 17:51:14.663 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-pro-_u2Tn2rSoAPffvE7JO6"
2021-09-21 17:51:14.663 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-sm-cali07d7014d27b" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.663 [INFO][69] felix/endpoint_mgr.go 614: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"}
2021-09-21 17:51:14.664 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.664 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-fw-cali07d7014d27b"
2021-09-21 17:51:14.664 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.664 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-tw-cali07d7014d27b"
2021-09-21 17:51:14.664 [INFO][69] felix/endpoint_mgr.go 1145: Applying /proc/sys configuration to interface. ifaceName="cali07d7014d27b"
2021-09-21 17:51:14.665 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.665 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.665 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.665 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="mangle"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-set-endpoint-mark" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 580: Chain became referenced, marking it for programming chainName="cali-sm-cali07d7014d27b"
2021-09-21 17:51:14.666 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-from-endpoint-mark" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.666 [INFO][69] felix/endpoint_mgr.go 476: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"}
2021-09-21 17:51:14.667 [INFO][69] felix/status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"}
2021-09-21 17:51:14.667 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2021-09-21 17:51:14.667 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2021-09-21 17:51:14.762 [INFO][69] felix/masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2021-09-21 17:51:14.762 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2021-09-21 17:51:14.762 [INFO][69] felix/ipip_mgr.go 222: All-hosts IP set out-of sync, refreshing it.
2021-09-21 17:51:14.762 [INFO][69] felix/ipsets.go 126: Queueing IP set for creation family="inet" setID="all-hosts-net" setType="hash:net"
2021-09-21 17:51:14.762 [INFO][69] felix/table.go 506: Queueing update of chain. chainName="cali-cidr-block" ipVersion=0x4 table="filter"
2021-09-21 17:51:14.763 [INFO][69] felix/wireguard.go 1605: Trying to connect to linkClient
2021-09-21 17:51:14.763 [INFO][69] felix/route_table.go 417: Trying to connect to netlink
2021-09-21 17:51:14.764 [INFO][69] felix/route_table.go 417: Trying to connect to netlink
2021-09-21 17:51:14.766 [INFO][69] felix/route_rule.go 176: Trying to connect to netlink
2021-09-21 17:51:14.769 [INFO][69] felix/wireguard.go 570: Public key out of sync or updated ourPublicKey=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=
2021-09-21 17:51:15.571 [INFO][69] felix/ipsets.go 760: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2021-09-21 17:51:15.572 [INFO][69] felix/ipsets.go 760: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2021-09-21 17:51:15.572 [INFO][69] felix/ipsets.go 760: Doing full IP set rewrite family="inet" numMembersInPendingReplace=7 setID="this-host"
2021-09-21 17:51:15.572 [INFO][69] felix/ipsets.go 760: Doing full IP set rewrite family="inet" numMembersInPendingReplace=2 setID="all-hosts-net"
2021-09-21 17:51:17.670 [INFO][69] felix/status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"} ipVersion=0x4 status="up"
2021-09-21 17:51:17.671 [INFO][69] felix/status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-8474476ff8-b6lqz", EndpointId:"eth0"} status="up"
2021-09-21 17:51:17.861 [INFO][69] felix/int_dataplane.go 1595: Completed first update to dataplane. secsSinceStart=15.5974772
2021-09-21 17:51:18.367 [INFO][69] felix/health.go 133: Health of component changed lastReport=health.HealthReport{Live:true, Ready:false} name="int_dataplane" newReport=&health.HealthReport{Live:true, Ready:true}
2021-09-21 17:51:19.762 [INFO][69] felix/health.go 196: Overall health status changed newStatus=&health.HealthReport{Live:true, Ready:true}
bird: Mesh_192_168_231_41: Connected to table master
bird: Mesh_192_168_231_41: State changed to feed
bird: Mesh_192_168_231_41: State changed to up
bird: Graceful restart done
bird: Mesh_192_168_231_41: State changed to start
2021-09-21 17:52:13.461 [INFO][69] felix/summary.go 100: Summarising 12 dataplane reconciliation loops over 1m6.1s: avg=877ms longest=3.392s (resync-filter-v4,resync-ipsets-v4,resync-mangle-v4,resync-nat-v4,resync-raw-v4,resync-routes-v4,resync-routes-v4,resync-rules-v4,update-ipsets-4)
bird: Mesh_192_168_231_41: State changed to feed
bird: Mesh_192_168_231_41: State changed to up
2021-09-21 17:53:16.670 [INFO][69] felix/summary.go 100: Summarising 9 dataplane reconciliation loops over 1m3.2s: avg=175ms longest=1.007s (resync-filter-v4,resync-raw-v4)
bird: Mesh_192_168_231_41: State changed to start
2021-09-21 17:54:21.192 [INFO][69] felix/summary.go 100: Summarising 9 dataplane reconciliation loops over 1m4.5s: avg=157ms longest=508ms (resync-ipsets-v4)
bird: Mesh_192_168_231_41: State changed to feed
bird: Mesh_192_168_231_41: State changed to up
bird: Mesh_192_168_231_41: State changed to start
2021-09-21 17:55:23.265 [INFO][69] felix/summary.go 100: Summarising 10 dataplane reconciliation loops over 1m2.1s: avg=276ms longest=681ms (resync-ipsets-v4)
bird: Mesh_192_168_231_41: State changed to feed
bird: Mesh_192_168_231_41: State changed to up
2021-09-21 17:56:25.434 [INFO][69] felix/summary.go 100: Summarising 9 dataplane reconciliation loops over 1m2.2s: avg=228ms longest=997ms (resync-filter-v4,resync-nat-v4,resync-raw-v4)
bird: Mesh_192_168_231_41: State changed to start
2021-09-21 17:57:27.440 [INFO][69] felix/summary.go 100: Summarising 8 dataplane reconciliation loops over 1m2s: avg=119ms longest=395ms (resync-mangle-v4)
bird: Mesh_192_168_231_41: State changed to feed
bird: Mesh_192_168_231_41: State changed to up
bird: Mesh_192_168_231_41: State changed to start

@HoseinGhanbari
Copy link
Author

Fortunately increasing timeoutSeconds for both livenessProbe & readinessProbe from 1 to 60 fixes the issue.

kubectl edit -n kube-system daemonset.apps/calico-node
kubectl edit -n kube-system deployment.apps/calico-kube-controllers

@caseydavenport Thank you very much

@nielsvbrecht
Copy link

How can we solve this when we deploy the tigera crd's? I dont see any option. Editing the deployment or daemonset is not a feasible option in a CI/CD pipeline right?

@julienlau
Copy link

julienlau commented Nov 15, 2022 •
edited
Loading

What is the impact of increasing the timeouts ?
If calico is stucked at T0, Node/pod eviction will not occur before timeout + delay to spawn a new calico controller ?

@axeII axeII mentioned this issue Jan 10, 2023
Closed
@GProjectdev GProjectdev mentioned this issue Jul 26, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/support
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@caseydavenport @julienlau @nielsvbrecht @HoseinGhanbari