Skip to content

Instantly share code, notes, and snippets.

@piengeng
Created April 5, 2020 12:08
Show Gist options
  • Select an option

  • Save piengeng/5639aa1ef8720df7fb6044aea4953cc2 to your computer and use it in GitHub Desktop.

Select an option

Save piengeng/5639aa1ef8720df7fb6044aea4953cc2 to your computer and use it in GitHub Desktop.
calico-node's log
$ kc logs calico-node-l8lqw
2020-04-05 12:05:48.158 [INFO][8] startup.go 290: Early log level set to info
2020-04-05 12:05:48.158 [INFO][8] startup.go 306: Using NODENAME environment for node name
2020-04-05 12:05:48.158 [INFO][8] startup.go 318: Determined node name: kw2.home
2020-04-05 12:05:48.159 [INFO][8] startup.go 350: Checking datastore connection
2020-04-05 12:05:48.178 [INFO][8] startup.go 374: Datastore connection verified
2020-04-05 12:05:48.178 [INFO][8] startup.go 102: Datastore is ready
2020-04-05 12:05:48.186 [INFO][8] startup.go 652: Using autodetected IPv4 address on interface eth0: 192.168.1.71/24
2020-04-05 12:05:48.186 [INFO][8] startup.go 715: No AS number configured on node resource, using global value
2020-04-05 12:05:48.187 [INFO][8] startup.go 171: Setting NetworkUnavailable to False
2020-04-05 12:05:48.199 [INFO][8] startup.go 764: found v6= in the kubeadm config map
2020-04-05 12:05:48.201 [INFO][8] startup.go 598: FELIX_IPV6SUPPORT is false through environment variable
2020-04-05 12:05:48.205 [INFO][8] startup.go 215: Using node name: kw2.home
2020-04-05 12:05:48.243 [INFO][20] allocateip.go 144: Current address is still valid, do nothing currentAddr="10.244.167.128" type="ipipTunnelAddress"
Calico node started successfully
bird: bird: Unable to open configuration file /etc/calico/confd/config/bird6.cfg: No such file or directory
Unable to open configuration file /etc/calico/confd/config/bird.cfg: No such file or directory
2020-04-05 12:05:49.284 [INFO][48] config.go 103: Skipping confd config file.
2020-04-05 12:05:49.284 [INFO][47] logutils.go 82: Early screen log level set to info
2020-04-05 12:05:49.285 [INFO][48] run.go 17: Starting calico-confd
2020-04-05 12:05:49.285 [INFO][47] daemon.go 144: Felix starting up GOMAXPROCS=4 builddate="c769a233f3ade99114fa130428ef5037ee297135" gitcommit="2020-03-30T20:02:38+0000" version="v3.13.2"
2020-04-05 12:05:49.285 [INFO][47] daemon.go 162: Loading configuration...
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdscheme"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdkeyfile"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "healthenabled"="true"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdcafile"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdendpoints"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "felixhostname"="kw2.home"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "datastoretype"="kubernetes"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdcertfile"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "etcdaddr"=""
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "defaultendpointtohostaction"="ACCEPT"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "logseverityscreen"="info"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "ipinipmtu"="1440"
2020-04-05 12:05:49.286 [INFO][47] env_var_loader.go 40: Found felix environment variable: "ipv6support"="false"
2020-04-05 12:05:49.286 [INFO][47] daemon.go 186: Loading config file: /etc/calico/felix.cfg
2020-04-05 12:05:49.286 [INFO][47] config_params.go 268: Merging in config from environment variable: map[datastoretype:kubernetes defaultendpointtohostaction:ACCEPT etcdaddr: etcdcafile: etcdcertfile: etcdendpoints: etcdkeyfile: etcdscheme: felixhostname:kw2.home healthenabled:true ipinipmtu:1440 ipv6support:false logseverityscreen:info]
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdkeyfile" source=environment variable
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdendpoints" source=environment variable
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdcertfile" source=environment variable
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdaddr" source=environment variable
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdscheme" source=environment variable
2020-04-05 12:05:49.286 [INFO][47] config_params.go 277: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdcafile" source=environment variable
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 268: Merging in config from config file: map[LogFilePath:None LogSeverityFile:None LogSeveritySys:None MetadataAddr:None]
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.287 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 349: Parsing value for MetadataAddr: None (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.288 [INFO][47] config_params.go 385: Parsed value for MetadataAddr: (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 349: Parsing value for LogFilePath: None (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.288 [INFO][47] config_params.go 385: Parsed value for LogFilePath: (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 349: Parsing value for LogSeverityFile: None (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.288 [INFO][47] config_params.go 385: Parsed value for LogSeverityFile: (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 349: Parsing value for LogSeveritySys: None (from config file)
2020-04-05 12:05:49.288 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.288 [INFO][47] config_params.go 385: Parsed value for LogSeveritySys: (from config file)
2020-04-05 12:05:49.288 [INFO][47] health.go 233: Health enabled. Starting server. host="localhost" port=9099
2020-04-05 12:05:49.288 [INFO][47] config_params.go 470: Encap disabled, disabling node poll (if KDD is in use).
2020-04-05 12:05:49.288 [INFO][47] daemon.go 218: Connecting to datastore datastore="kubernetes"
2020-04-05 12:05:49.290 [INFO][47] daemon.go 225: Created datastore client
2020-04-05 12:05:49.294 [INFO][48] watchersyncer.go 89: Start called
2020-04-05 12:05:49.294 [INFO][48] client.go 362: RouteGenerator has indicated it is in sync
2020-04-05 12:05:49.294 [INFO][48] watchersyncer.go 127: Sending status update Status=wait-for-ready
2020-04-05 12:05:49.294 [INFO][48] watchersyncer.go 147: Starting main event processing loop
2020-04-05 12:05:49.297 [INFO][48] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/bgppeers"
2020-04-05 12:05:49.297 [INFO][48] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.297 [INFO][48] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/bgpconfigurations"
2020-04-05 12:05:49.297 [INFO][48] watchercache.go 291: Sending synced update ListRoot="/calico/ipam/v2/host/kw2.home"
2020-04-05 12:05:49.300 [INFO][48] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2020-04-05 12:05:49.297 [INFO][48] watchersyncer.go 127: Sending status update Status=resync
2020-04-05 12:05:49.300 [INFO][48] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.300 [INFO][48] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.300 [INFO][48] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.301 [INFO][48] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2020-04-05 12:05:49.301 [INFO][47] daemon.go 845: Loaded ready flag kind="ClusterInformation" name="default" ready=true
2020-04-05 12:05:49.301 [INFO][48] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.301 [INFO][48] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2020-04-05 12:05:49.302 [INFO][48] watchersyncer.go 127: Sending status update Status=in-sync
2020-04-05 12:05:49.302 [INFO][48] client.go 352: Calico Syncer has indicated it is in sync
2020-04-05 12:05:49.302 [INFO][48] resource.go 220: Target config /tmp/tunl-ip out of sync
2020-04-05 12:05:49.303 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird6_aggr.cfg out of sync
2020-04-05 12:05:49.303 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird6_ipam.cfg out of sync
2020-04-05 12:05:49.303 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird_aggr.cfg out of sync
2020-04-05 12:05:49.303 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird.cfg out of sync
2020-04-05 12:05:49.302 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird_ipam.cfg out of sync
2020-04-05 12:05:49.302 [INFO][48] resource.go 220: Target config /etc/calico/confd/config/bird6.cfg out of sync
2020-04-05 12:05:49.312 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird6_ipam.cfg has been updated
2020-04-05 12:05:49.314 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird_aggr.cfg has been updated
2020-04-05 12:05:49.316 [INFO][47] daemon.go 825: No config of this type kind="FelixConfiguration" name="node.kw2.home"
2020-04-05 12:05:49.316 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird6_aggr.cfg has been updated
2020-04-05 12:05:49.318 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird.cfg has been updated
2020-04-05 12:05:49.319 [INFO][47] config_params.go 268: Merging in config from datastore (global): map[CalicoVersion:v3.13.2 ClusterGUID:8650601e13aa40dc976eea0977fd497b ClusterType:k8s,bgp,kubeadm,kdd IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0]
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.319 [INFO][47] config_params.go 349: Parsing value for MetadataAddr: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for MetadataAddr: (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogFilePath: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for LogFilePath: (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogSeverityFile: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for LogSeverityFile: (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogSeveritySys: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for LogSeveritySys: (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: Info (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2020-04-05 12:05:49.320 [INFO][47] config_params.go 388: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2020-04-05 12:05:49.320 [INFO][47] config_params.go 268: Merging in config from datastore (per-host): map[IpInIpTunnelAddr:10.244.167.128]
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for MetadataAddr: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.320 [INFO][47] config_params.go 385: Parsed value for MetadataAddr: (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 349: Parsing value for LogFilePath: None (from config file)
2020-04-05 12:05:49.320 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for LogFilePath: (from config file)
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for LogSeverityFile: None (from config file)
2020-04-05 12:05:49.321 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for LogSeverityFile: (from config file)
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for LogSeveritySys: None (from config file)
2020-04-05 12:05:49.321 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for LogSeveritySys: (from config file)
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: Info (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 388: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 349: Parsing value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.321 [INFO][47] config_params.go 385: Parsed value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.322 [INFO][47] daemon.go 279: Using Kubernetes datastore driver, sharing Kubernetes client with datastore driver.
2020-04-05 12:05:49.322 [INFO][47] health.go 133: Health of component changed lastReport=health.HealthReport{Live:true, Ready:false} name="felix-startup" newReport=&health.HealthReport{Live:true, Ready:true}
2020-04-05 12:05:49.322 [INFO][47] health.go 230: Health enabled. Server is already running. host="localhost" port=9099
2020-04-05 12:05:49.322 [INFO][47] daemon.go 331: Successfully loaded configuration. GOMAXPROCS=4 builddate="c769a233f3ade99114fa130428ef5037ee297135" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", BPFEnabled:false, BPFLogLevel:"off", BPFDataIfacePattern:(*regexp.Regexp)(0xc0001e08c0), BPFConnectTimeLoadBalancingEnabled:true, BPFExternalServiceMode:"tunnel", BPFKubeProxyIptablesCleanupEnabled:true, BPFKubeProxyMinSyncPeriod:1000000000, DebugBPFCgroupV2:"", DebugBPFMapRepinEnabled:true, DatastoreType:"kubernetes", FelixHostname:"kw2.home", 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, DeviceRouteSourceAddress:net.IP(nil), DeviceRouteProtocol:3, RemoveExternalRoutes:true, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, XDPRefreshInterval:90000000000, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, OpenstackRegion:"", InterfacePrefix:"cali", InterfaceExclude:[]*regexp.Regexp{(*regexp.Regexp)(0xc0001e0aa0)}, ChainInsertMode:"insert", DefaultEndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", VXLANEnabled:false, VXLANPort:4789, VXLANVNI:4096, VXLANMTU:1410, IPv4VXLANTunnelAddr:net.IP(nil), VXLANTunnelMACAddr:"", IpInIpEnabled:true, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xa, 0xf4, 0xa7, 0x80}, 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{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{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:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"8650601e13aa40dc976eea0977fd497b", ClusterType:"k8s,bgp,kubeadm,kdd", CalicoVersion:"v3.13.2", ExternalNodesCIDRList:[]string(nil), DebugMemoryProfilePath:"", DebugCPUProfilePath:"/tmp/felix-cpu-<timestamp>.pprof", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, sourceToRawConfig:map[config.Source]map[string]string{0x1:map[string]string{"CalicoVersion":"v3.13.2", "ClusterGUID":"8650601e13aa40dc976eea0977fd497b", "ClusterType":"k8s,bgp,kubeadm,kdd", "IpInIpEnabled":"true", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"}, 0x2:map[string]string{"IpInIpTunnelAddr":"10.244.167.128"}, 0x3:map[string]string{"LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None"}, 0x4:map[string]string{"datastoretype":"kubernetes", "defaultendpointtohostaction":"ACCEPT", "felixhostname":"kw2.home", "healthenabled":"true", "ipinipmtu":"1440", "ipv6support":"false", "logseverityscreen":"info"}}, rawValues:map[string]string{"CalicoVersion":"v3.13.2", "ClusterGUID":"8650601e13aa40dc976eea0977fd497b", "ClusterType":"k8s,bgp,kubeadm,kdd", "DatastoreType":"kubernetes", "DefaultEndpointToHostAction":"ACCEPT", "FelixHostname":"kw2.home", "HealthEnabled":"true", "IpInIpEnabled":"true", "IpInIpMtu":"1440", "IpInIpTunnelAddr":"10.244.167.128", "Ipv6Support":"false", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeverityScreen":"info", "LogSeveritySys":"None", "MetadataAddr":"None", "ReportingIntervalSecs":"0"}, Err:error(nil), IptablesNATOutgoingInterfaceFilter:"", SidecarAccelerationEnabled:false, XDPEnabled:true, GenericXDPEnabled:false, loadClientConfigFromEnvironment:(func() (*apiconfig.CalicoAPIConfig, error))(0x117d6e0), useNodeResourceUpdates:false} gitcommit="2020-03-30T20:02:38+0000" version="v3.13.2"
2020-04-05 12:05:49.323 [INFO][47] driver.go 48: Using internal (linux) dataplane driver.
2020-04-05 12:05:49.323 [INFO][47] driver.go 90: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2020-04-05 12:05:49.323 [INFO][47] int_dataplane.go 261: Creating internal dataplane driver. config=intdataplane.Config{Hostname:"kw2.home", IPv6Enabled:false, RuleRendererOverride:rules.RuleRenderer(nil), IPIPMTU:1440, VXLANMTU:1410, 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:0, IptablesLockProbeInterval:50000000, XDPRefreshInterval:90000000000, NetlinkTimeout:10000000000, RulesConfig:rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc000321a40), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc000321b80), 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:false, 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, 0xf4, 0xa7, 0x80}, VXLANTunnelAddress:net.IP(nil), IptablesLogPrefix:"calico-packet", EndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, IptablesNATOutgoingInterfaceFilter:"", NATOutgoingAddress:net.IP(nil), BPFEnabled:false}, IfaceMonitorConfig:ifacemonitor.Config{InterfaceExcludes:[]*regexp.Regexp{(*regexp.Regexp)(0xc0001e0aa0)}}, StatusReportingInterval:0, ConfigChangedRestartCallback:(func())(0x189a0a0), PostInSyncCallback:(func())(0x187ebe0), HealthAggregator:(*health.HealthAggregator)(0xc000148900), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil), BPFEnabled:false, BPFKubeProxyIptablesCleanupEnabled:true, BPFLogLevel:"off", BPFDataIfacePattern:(*regexp.Regexp)(0xc0001e08c0), XDPEnabled:true, XDPAllowGeneric:false, BPFConntrackTimeouts:conntrack.Timeouts{CreationGracePeriod:10000000000, TCPPreEstablished:20000000000, TCPEstablished:3600000000000, TCPFinsSeen:30000000000, TCPResetSeen:40000000000, UDPLastSeen:60000000000, ICMPLastSeen:5000000000}, BPFCgroupV2:"", BPFConnTimeLBEnabled:true, BPFMapRepin:true, BPFNodePortDSREnabled:false, KubeProxyMinSyncPeriod:1000000000, SidecarAccelerationEnabled:false, LookPathOverride:(func(string) (string, error))(nil), KubeClientSet:(*kubernetes.Clientset)(0xc00019a500)}
2020-04-05 12:05:49.323 [INFO][47] rule_defs.go 311: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc000321a40), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc000321b80), 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:false, 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, 0xf4, 0xa7, 0x80}, VXLANTunnelAddress:net.IP(nil), IptablesLogPrefix:"calico-packet", EndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, IptablesNATOutgoingInterfaceFilter:"", NATOutgoingAddress:net.IP(nil), BPFEnabled:false}
2020-04-05 12:05:49.323 [INFO][47] rule_defs.go 321: Workload to host packets will be accepted.
2020-04-05 12:05:49.323 [INFO][47] rule_defs.go 335: filter table allowed packets will be accepted immediately.
2020-04-05 12:05:49.323 [INFO][47] rule_defs.go 343: mangle table allowed packets will be accepted immediately.
2020-04-05 12:05:49.323 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird_ipam.cfg has been updated
2020-04-05 12:05:49.323 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"ip6tables-legacy-save", "ip6tables-save"} command="ip6tables-legacy-save" ipVersion=0x6 saveOrRestore="save"
2020-04-05 12:05:49.323 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2020-04-05 12:05:49.328 [INFO][48] resource.go 260: Target config /etc/calico/confd/config/bird6.cfg has been updated
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 112: Updating detected iptables features features=iptables.Features{SNATFullyRandom:false, MASQFullyRandom:false, RestoreSupportsLock:true} iptablesVersion=1.8.2 kernelVersion=3.10.0
2020-04-05 12:05:49.333 [INFO][47] table.go 317: 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-"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2020-04-05 12:05:49.333 [INFO][47] table.go 317: 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"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2020-04-05 12:05:49.333 [INFO][47] table.go 317: 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-"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2020-04-05 12:05:49.333 [INFO][47] table.go 317: 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-"
2020-04-05 12:05:49.333 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-restore", "iptables-restore"} command="iptables-legacy-restore" ipVersion=0x4 saveOrRestore="restore"
2020-04-05 12:05:49.334 [INFO][47] feature_detect.go 234: Looked up iptables command backendMode="legacy" candidates=[]string{"iptables-legacy-save", "iptables-save"} command="iptables-legacy-save" ipVersion=0x4 saveOrRestore="save"
2020-04-05 12:05:49.334 [INFO][47] int_dataplane.go 390: Checking if we need to clean up the VXLAN device
2020-04-05 12:05:49.334 [WARNING][47] int_dataplane.go 392: Failed to query VXLAN device error=Link not found
2020-04-05 12:05:49.334 [WARNING][47] int_dataplane.go 404: Can't enable XDP acceleration. error=kernel is too old (have: 3.10.0 but want at least: 4.16.0)
2020-04-05 12:05:49.341 [INFO][47] int_dataplane.go 477: Failed to remove BPF connect-time load balancer, ignoring. error=failed to set-up cgroupv2: no such device
2020-04-05 12:05:49.345 [INFO][47] route_table.go 170: Calculated interface name regexp regex="^cali.*"
2020-04-05 12:05:49.345 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2020-04-05 12:05:49.345 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2020-04-05 12:05:49.345 [INFO][47] int_dataplane.go 676: Registering to report health.
2020-04-05 12:05:49.346 [INFO][47] int_dataplane.go 1209: attempted to modprobe nf_conntrack_proto_sctp error=exit status 1 output=""
2020-04-05 12:05:49.346 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.346 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.346 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2020-04-05 12:05:49.347 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 813: IPIP enabled, starting thread to keep tunnel configuration in sync.
2020-04-05 12:05:49.347 [INFO][47] daemon.go 350: Connect to the dataplane driver.
2020-04-05 12:05:49.347 [INFO][47] ipip_mgr.go 85: IPIP thread started.
2020-04-05 12:05:49.347 [INFO][47] daemon.go 422: using resource updates where applicable
2020-04-05 12:05:49.347 [INFO][47] daemon.go 425: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc00064ccf0), (*watchersyncer.watcherCache)(0xc00064cd80), (*watchersyncer.watcherCache)(0xc00064ce10), (*watchersyncer.watcherCache)(0xc00064cea0), (*watchersyncer.watcherCache)(0xc00064cf30), (*watchersyncer.watcherCache)(0xc00064cfc0), (*watchersyncer.watcherCache)(0xc00064d050), (*watchersyncer.watcherCache)(0xc00064d0e0), (*watchersyncer.watcherCache)(0xc00064d170), (*watchersyncer.watcherCache)(0xc00064d200), (*watchersyncer.watcherCache)(0xc00064d290), (*watchersyncer.watcherCache)(0xc00064d320)}, results:(chan interface {})(0xc000152cc0), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc000010128), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2020-04-05 12:05:49.347 [INFO][47] daemon.go 429: Starting the datastore Syncer
2020-04-05 12:05:49.347 [INFO][47] watchersyncer.go 89: Start called
2020-04-05 12:05:49.347 [INFO][47] calc_graph.go 110: Creating calculation graph, filtered to hostname kw2.home
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1657ee0)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1657ee0)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1657fc0)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1657fc0)
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 1395: Started internal status report thread
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 1397: Process status reports disabled
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 988: Started internal iptables dataplane driver loop
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 998: Will refresh IP sets on timer interval=1m30s
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] int_dataplane.go 1008: Will refresh routes on timer interval=1m30s
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x1657db0)
2020-04-05 12:05:49.347 [INFO][47] iface_monitor.go 87: Interface monitoring thread started.
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x156d370)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x156d370)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x156d370)
2020-04-05 12:05:49.347 [INFO][47] iface_monitor.go 94: Subscribed to netlink updates.
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x156d370)
2020-04-05 12:05:49.347 [INFO][47] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x156d370)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1658450)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1658450)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1658450)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x1658130)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x1658130)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x1658050)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x1658050)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x1658050)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x16585a0)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x1658630)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1658630)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1658630)
2020-04-05 12:05:49.348 [INFO][47] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x1658630)
2020-04-05 12:05:49.348 [INFO][47] async_calc_graph.go 234: Starting AsyncCalcGraph
2020-04-05 12:05:49.348 [INFO][47] daemon.go 535: Started the processing graph
2020-04-05 12:05:49.348 [INFO][47] daemon.go 906: Reading from dataplane driver pipe...
2020-04-05 12:05:49.348 [INFO][47] watchersyncer.go 127: Sending status update Status=wait-for-ready
2020-04-05 12:05:49.348 [INFO][47] watchersyncer.go 147: Starting main event processing loop
2020-04-05 12:05:49.349 [INFO][47] async_calc_graph.go 135: AsyncCalcGraph running
2020-04-05 12:05:49.349 [INFO][47] int_dataplane.go 1034: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.13.2" > config:<key:"ClusterGUID" value:"8650601e13aa40dc976eea0977fd497b" > config:<key:"ClusterType" value:"k8s,bgp,kubeadm,kdd" > config:<key:"DatastoreType" value:"kubernetes" > config:<key:"DefaultEndpointToHostAction" value:"ACCEPT" > config:<key:"FelixHostname" value:"kw2.home" > config:<key:"HealthEnabled" value:"true" > config:<key:"IpInIpEnabled" value:"true" > config:<key:"IpInIpMtu" value:"1440" > config:<key:"IpInIpTunnelAddr" value:"10.244.167.128" > 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:"ReportingIntervalSecs" value:"0" >
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 743: Linux interface state changed. ifIndex=1 ifaceName="lo" state="up"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 1049: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up", Index:1}
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 778: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}} ifaceName="lo"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 743: Linux interface state changed. ifIndex=2 ifaceName="eth0" state="up"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 778: Linux interface addrs changed. addrs=set.mapSet{"192.168.1.71":set.empty{}} ifaceName="eth0"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 778: Linux interface addrs changed. addrs=set.mapSet{"172.17.0.1":set.empty{}} ifaceName="docker0"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 1049: Received interface update msg=&intdataplane.ifaceUpdate{Name:"eth0", State:"up", Index:2}
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 743: Linux interface state changed. ifIndex=4 ifaceName="tunl0" state="up"
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 1049: Received interface update msg=&intdataplane.ifaceUpdate{Name:"tunl0", State:"up", Index:4}
2020-04-05 12:05:49.350 [INFO][47] int_dataplane.go 1067: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2020-04-05 12:05:49.351 [INFO][47] int_dataplane.go 1067: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"eth0", Addrs:set.mapSet{"192.168.1.71":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] int_dataplane.go 778: Linux interface addrs changed. addrs=set.mapSet{"10.244.167.128":set.empty{}} ifaceName="tunl0"
2020-04-05 12:05:49.351 [INFO][47] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"eth0", Addrs:set.mapSet{"192.168.1.71":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2020-04-05 12:05:49.351 [INFO][47] int_dataplane.go 1067: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"docker0", Addrs:set.mapSet{"172.17.0.1":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"docker0", Addrs:set.mapSet{"172.17.0.1":set.empty{}}}
2020-04-05 12:05:49.351 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2020-04-05 12:05:49.354 [INFO][47] int_dataplane.go 1067: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{"10.244.167.128":set.empty{}}}
2020-04-05 12:05:49.354 [INFO][47] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{"10.244.167.128":set.empty{}}}
2020-04-05 12:05:49.354 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2020-04-05 12:05:49.356 [INFO][47] daemon.go 631: No driver process to monitor
2020-04-05 12:05:49.356 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2020-04-05 12:05:49.356 [INFO][47] watchersyncer.go 127: Sending status update Status=resync
2020-04-05 12:05:49.356 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.357 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 8650601e13aa40dc976eea0977fd497b 1027 <nil> 0s} 1}
2020-04-05 12:05:49.357 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp,kubeadm,kdd 1027 <nil> 0s} 1}
2020-04-05 12:05:49.357 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.13.2 1027 <nil> 0s} 1}
2020-04-05 12:05:49.357 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2020-04-05 12:05:49.357 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.358 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 1028 <nil> 0s} 1}
2020-04-05 12:05:49.358 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=IpInIpEnabled) true 1028 <nil> 0s} 1}
2020-04-05 12:05:49.358 [INFO][47] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 1028 <nil> 0s} 1}
2020-04-05 12:05:49.355 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2020-04-05 12:05:49.358 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.360 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networksets"
2020-04-05 12:05:49.360 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.360 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2020-04-05 12:05:49.360 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.360 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2020-04-05 12:05:49.360 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.361 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/ipam/v2/assignment/"
2020-04-05 12:05:49.361 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.361 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2020-04-05 12:05:49.361 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.366 [INFO][48] resource.go 260: Target config /tmp/tunl-ip has been updated
2020-04-05 12:05:49.367 [INFO][47] int_dataplane.go 1034: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"10.244.0.0-16" pool:<cidr:"10.244.0.0/16" masquerade:true >
2020-04-05 12:05:49.368 [INFO][47] config_batcher.go 61: Host config update for this host: {{HostConfig(node=kw2.home,name=IpInIpTunnelAddr) 10.244.167.128 29055 <nil> 0s} 1}
2020-04-05 12:05:49.369 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2020-04-05 12:05:49.369 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.369 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2020-04-05 12:05:49.371 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.371 [INFO][47] int_dataplane.go 1034: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"km1.home" ipv4_addr:"192.168.1.60"
2020-04-05 12:05:49.371 [INFO][47] int_dataplane.go 1034: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"kw1.home" ipv4_addr:"192.168.1.70"
2020-04-05 12:05:49.371 [INFO][47] int_dataplane.go 1034: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"kw2.home" ipv4_addr:"192.168.1.71"
2020-04-05 12:05:49.371 [INFO][47] int_dataplane.go 1034: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"kw3.home" ipv4_addr:"192.168.1.72"
2020-04-05 12:05:49.372 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2020-04-05 12:05:49.373 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.373 [INFO][47] watchercache.go 291: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2020-04-05 12:05:49.373 [INFO][47] watchersyncer.go 209: Received InSync event from one of the watcher caches
2020-04-05 12:05:49.373 [INFO][47] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2020-04-05 12:05:49.373 [INFO][47] watchersyncer.go 127: Sending status update Status=in-sync
2020-04-05 12:05:49.374 [INFO][47] config_batcher.go 102: Datamodel in sync, flushing config update
2020-04-05 12:05:49.374 [INFO][47] config_batcher.go 112: Sending config update global: map[CalicoVersion:v3.13.2 ClusterGUID:8650601e13aa40dc976eea0977fd497b ClusterType:k8s,bgp,kubeadm,kdd IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[IpInIpTunnelAddr:10.244.167.128].
2020-04-05 12:05:49.374 [INFO][47] async_calc_graph.go 165: First time we've been in sync
2020-04-05 12:05:49.374 [INFO][47] usagerep.go 83: Waiting before first check-in delay=5m0.233s
2020-04-05 12:05:49.374 [INFO][47] 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}
2020-04-05 12:05:49.374 [INFO][47] event_sequencer.go 227: Possible config update. global=map[string]string{"CalicoVersion":"v3.13.2", "ClusterGUID":"8650601e13aa40dc976eea0977fd497b", "ClusterType":"k8s,bgp,kubeadm,kdd", "IpInIpEnabled":"true", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"} host=map[string]string{"IpInIpTunnelAddr":"10.244.167.128"}
2020-04-05 12:05:49.374 [INFO][47] config_params.go 268: Merging in config from datastore (global): map[CalicoVersion:v3.13.2 ClusterGUID:8650601e13aa40dc976eea0977fd497b ClusterType:k8s,bgp,kubeadm,kdd IpInIpEnabled:true LogSeverityScreen:Info ReportingIntervalSecs:0]
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 349: Parsing value for MetadataAddr: None (from config file)
2020-04-05 12:05:49.374 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for MetadataAddr: (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for LogFilePath: None (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for LogFilePath: (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for LogSeverityFile: None (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for LogSeverityFile: (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for LogSeveritySys: None (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for LogSeveritySys: (from config file)
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: Info (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 388: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 385: Parsed value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.375 [INFO][47] config_params.go 349: Parsing value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.376 [INFO][47] config_params.go 268: Merging in config from datastore (per-host): map[IpInIpTunnelAddr:10.244.167.128]
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for FelixHostname: kw2.home (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for DatastoreType: kubernetes (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: info (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for Ipv6Support: false (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for IpInIpMtu: 1440 (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for HealthEnabled: true (from environment variable)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for LogFilePath: None (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for LogFilePath: (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for LogSeverityFile: None (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for LogSeverityFile: (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for LogSeveritySys: None (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for LogSeveritySys: (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for MetadataAddr: None (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 366: Value set to 'none', replacing with zero-value: "".
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for MetadataAddr: (from config file)
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for IpInIpTunnelAddr: 10.244.167.128 (from datastore (per-host))
2020-04-05 12:05:49.376 [INFO][47] config_params.go 349: Parsing value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.376 [INFO][47] config_params.go 385: Parsed value for ClusterGUID: 8650601e13aa40dc976eea0977fd497b (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 349: Parsing value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 385: Parsed value for ClusterType: k8s,bgp,kubeadm,kdd (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 349: Parsing value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 385: Parsed value for CalicoVersion: v3.13.2 (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 349: Parsing value for LogSeverityScreen: Info (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 385: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 388: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2020-04-05 12:05:49.377 [INFO][47] config_params.go 349: Parsing value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 385: Parsed value for IpInIpEnabled: true (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 349: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] config_params.go 385: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2020-04-05 12:05:49.377 [INFO][47] async_calc_graph.go 214: First flush after becoming in sync, sending InSync message.
2020-04-05 12:05:49.377 [INFO][47] daemon.go 990: Datastore now in sync.
2020-04-05 12:05:49.377 [INFO][47] daemon.go 992: Datastore in sync for first time, sending message to status reporter.
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"endpoint-controller" > labels:<key:"projectcalico.org/name" value:"endpoint-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"statefulset-controller" > labels:<key:"projectcalico.org/name" value:"statefulset-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"calico-system" name:"calico-kube-controllers" > labels:<key:"projectcalico.org/name" value:"calico-kube-controllers" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"calico-system" name:"calico-node" > labels:<key:"projectcalico.org/name" value:"calico-node" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"node-controller" > labels:<key:"projectcalico.org/name" value:"node-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"calico-system" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"deployment-controller" > labels:<key:"projectcalico.org/name" value:"deployment-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"job-controller" > labels:<key:"projectcalico.org/name" value:"job-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"kube-proxy" > labels:<key:"projectcalico.org/name" value:"kube-proxy" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"replication-controller" > labels:<key:"projectcalico.org/name" value:"replication-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"resourcequota-controller" > labels:<key:"projectcalico.org/name" value:"resourcequota-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"token-cleaner" > labels:<key:"projectcalico.org/name" value:"token-cleaner" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"ttl-controller" > labels:<key:"projectcalico.org/name" value:"ttl-controller" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-public" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"coredns" > labels:<key:"projectcalico.org/name" value:"coredns" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"metallb-system" name:"speaker" > labels:<key:"app" value:"metallb" > labels:<key:"projectcalico.org/name" value:"speaker" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.377 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"service-controller" > labels:<key:"projectcalico.org/name" value:"service-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"disruption-controller" > labels:<key:"projectcalico.org/name" value:"disruption-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"expand-controller" > labels:<key:"projectcalico.org/name" value:"expand-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"attachdetach-controller" > labels:<key:"projectcalico.org/name" value:"attachdetach-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"bootstrap-signer" > labels:<key:"projectcalico.org/name" value:"bootstrap-signer" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"namespace-controller" > labels:<key:"projectcalico.org/name" value:"namespace-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"replicaset-controller" > labels:<key:"projectcalico.org/name" value:"replicaset-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"default" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-node-lease" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"metallb-system" name:"controller" > labels:<key:"app" value:"metallb" > labels:<key:"projectcalico.org/name" value:"controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"metallb-system" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"certificate-controller" > labels:<key:"projectcalico.org/name" value:"certificate-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"default" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: 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" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.ServiceAccountUpdate update from calculation graph msg=id:<namespace:"kube-system" name:"cronjob-controller" > labels:<key:"projectcalico.org/name" value:"cronjob-controller" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"calico-system" > labels:<key:"projectcalico.org/name" value:"calico-system" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"default" > labels:<key:"istio-injection" value:"enabled" > labels:<key:"projectcalico.org/name" value:"default" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-node-lease" > labels:<key:"projectcalico.org/name" value:"kube-node-lease" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-public" > labels:<key:"projectcalico.org/name" value:"kube-public" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"kube-system" > labels:<key:"projectcalico.org/name" value:"kube-system" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.NamespaceUpdate update from calculation graph msg=id:<name:"metallb-system" > labels:<key:"app" value:"metallb" > labels:<key:"projectcalico.org/name" value:"metallb-system" >
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1034: Received *proto.InSync update from calculation graph msg=
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1042: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=94.13987ms
2020-04-05 12:05:49.378 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:05:49.378 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.378 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.378 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.379 [INFO][47] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2020-04-05 12:05:49.379 [INFO][47] table.go 454: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2020-04-05 12:05:49.379 [INFO][47] ipip_mgr.go 222: All-hosts IP set out-of sync, refreshing it.
2020-04-05 12:05:49.379 [INFO][47] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-hosts-net" setType="hash:net"
2020-04-05 12:05:49.379 [INFO][47] route_table.go 247: Trying to connect to netlink
2020-04-05 12:05:49.379 [INFO][47] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2020-04-05 12:05:49.382 [INFO][47] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.886473ms
2020-04-05 12:05:49.382 [INFO][47] ipsets.go 749: Doing full IP set rewrite family="inet" numMembersInPendingReplace=4 setID="all-hosts-net"
2020-04-05 12:05:49.382 [INFO][47] ipsets.go 749: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2020-04-05 12:05:49.382 [INFO][47] ipsets.go 749: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2020-04-05 12:05:49.382 [INFO][47] ipsets.go 749: Doing full IP set rewrite family="inet" numMembersInPendingReplace=4 setID="this-host"
2020-04-05 12:05:49.400 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:05:49.403 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:05:49.404 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:05:49.407 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:05:49.410 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=31.357189
2020-04-05 12:05:49.410 [INFO][47] int_dataplane.go 1182: Completed first update to dataplane. secsSinceStart=0.125577561
2020-04-05 12:05:49.412 [INFO][47] health.go 133: Health of component changed lastReport=health.HealthReport{Live:true, Ready:false} name="int_dataplane" newReport=&health.HealthReport{Live:true, Ready:true}
2020-04-05 12:05:49.564 [INFO][47] health.go 196: Overall health status changed newStatus=&health.HealthReport{Live:true, Ready:true}
bird: device1: Initializing
bird: direct1: Initializing
bird: Mesh_192_168_1_60: Initializing
bird: Mesh_192_168_1_70: Initializing
bird: Mesh_192_168_1_72: Initializing
bird: device1: Starting
bird: device1: Initializing
bird: direct1: Initializing
bird: device1: Starting
bird: bird: device1: Connected to table master
device1: Connected to table master
bird: device1: State changed to feed
bird: device1: State changed to feed
bird: direct1: Starting
bird: bird: direct1: Connected to table masterdirect1: Starting
bird: bird: direct1: State changed to feeddirect1: Connected to table master
bird: bird: Graceful restart starteddirect1: State changed to feed
bird: bird: Graceful restart doneMesh_192_168_1_60: Starting
bird: Started
bird: Mesh_192_168_1_60: State changed to start
bird: bird: Mesh_192_168_1_70: Startingdevice1: State changed to up
bird: bird: Mesh_192_168_1_70: State changed to startdirect1: State changed to up
bird: Mesh_192_168_1_72: Starting
bird: Mesh_192_168_1_72: State changed to start
bird: Graceful restart started
bird: Started
bird: device1: State changed to up
bird: direct1: State changed to up
2020-04-05 12:05:50.344 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:05:50.344 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:05:50.344 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:05:50.344 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:05:50.344 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:05:50.345 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:05:50.347 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:05:50.348 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:05:50.350 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:05:50.353 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=8.689619
2020-04-05 12:05:51.342 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:05:51.342 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:05:51.342 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:05:51.342 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:05:51.342 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:05:51.343 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:05:51.344 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:05:51.345 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:05:51.347 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:05:51.350 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=8.331710000000001
2020-04-05 12:05:53.341 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:05:53.341 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:05:53.341 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:05:53.341 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:05:53.341 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:05:53.343 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:05:53.344 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:05:53.347 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:05:53.348 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:05:53.351 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=9.437237
2020-04-05 12:05:57.342 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:05:57.343 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:05:57.343 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:05:57.343 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:05:57.343 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:05:57.344 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:05:57.346 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:05:57.347 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:05:57.349 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:05:57.352 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=9.94545
2020-04-05 12:06:00.090 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:00.090 [INFO][47] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2020-04-05 12:06:00.090 [INFO][47] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2020-04-05 12:06:00.091 [INFO][47] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.057926ms
2020-04-05 12:06:00.091 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=1.421536
2020-04-05 12:06:05.333 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:05.333 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:06:05.333 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:06:05.335 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:06:05.336 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:06:05.339 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=5.603541
2020-04-05 12:06:05.339 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:05.339 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:06:05.339 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:06:05.340 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:06:05.343 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:06:05.347 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=7.915799
2020-04-05 12:06:10.378 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:10.378 [INFO][47] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2020-04-05 12:06:10.378 [INFO][47] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2020-04-05 12:06:10.379 [INFO][47] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.004626ms
2020-04-05 12:06:10.379 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=1.291633
2020-04-05 12:06:20.908 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:20.908 [INFO][47] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2020-04-05 12:06:20.908 [INFO][47] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2020-04-05 12:06:20.910 [INFO][47] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.094727ms
2020-04-05 12:06:20.910 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=1.407635
2020-04-05 12:06:21.333 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:21.333 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2020-04-05 12:06:21.333 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2020-04-05 12:06:21.334 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2020-04-05 12:06:21.336 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2020-04-05 12:06:21.338 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=5.033127
2020-04-05 12:06:21.338 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:21.338 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2020-04-05 12:06:21.339 [INFO][47] table.go 810: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2020-04-05 12:06:21.340 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2020-04-05 12:06:21.343 [INFO][47] table.go 497: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2020-04-05 12:06:21.345 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=6.925675
2020-04-05 12:06:31.341 [INFO][47] int_dataplane.go 1162: Applying dataplane updates
2020-04-05 12:06:31.341 [INFO][47] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2020-04-05 12:06:31.341 [INFO][47] ipsets.go 306: Resyncing ipsets with dataplane. family="inet"
2020-04-05 12:06:31.342 [INFO][47] ipsets.go 356: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.036826ms
2020-04-05 12:06:31.342 [INFO][47] int_dataplane.go 1176: Finished applying updates to dataplane. msecToApply=1.2868330000000001
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment