gistfile1.txt

2017-11-30 09:14:12.492980 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
Skipping datastore connection test
Using autodetected IPv4 address on interface eth0: 172.23.2.38/30
No AS number configured on node resource, using global value
Using node name: master-w3p6j-3696049930-sqgh9
time="2017-11-30T09:14:13Z" level=info msg="Loading config from environment" 
2017-11-30 09:14:13.155767 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
time="2017-11-30T09:14:13Z" level=info msg="Auto-assign 1 ipv4, 0 ipv6 addrs for host 'master-w3p6j-3696049930-sqgh9'" 
time="2017-11-30T09:14:13Z" level=info msg="Ran out of existing affine blocks for host 'master-w3p6j-3696049930-sqgh9'" 
time="2017-11-30T09:14:13Z" level=info msg="Need to allocate 1 more addresses - allocate another block" 
time="2017-11-30T09:14:13Z" level=info msg="Claiming a new affine block for host 'master-w3p6j-3696049930-sqgh9'" 
time="2017-11-30T09:14:13Z" level=info msg="Host master-w3p6j-3696049930-sqgh9 claiming block affinity for 192.168.24.128/26" 
time="2017-11-30T09:14:13Z" level=info msg="Claimed new block 192.168.24.128/26 - assigning 1 addresses" 
time="2017-11-30T09:14:13Z" level=info msg="New allocation attribute: {AttrPrimary:<nil> AttrSecondary:map[]}" 
time="2017-11-30T09:14:13Z" level=info msg="Auto-assigned 1 out of 1 IPv4s: [192.168.24.128]" 
time="2017-11-30T09:14:13Z" level=info msg="Set IPIP tunnel address" IP=192.168.24.128 
Calico node started successfully
bird: device1: Initializing
bird: direct1: Initializing
bird: Mesh_172_23_2_30: Initializing
bird: Mesh_172_23_2_42: Initializing
bird: Mesh_172_23_2_170: Initializing
bird: Mesh_172_23_2_70: Initializing
bird: device1: Starting
bird: device1: Connected to table master
bird: device1: State changed to feed
bird: direct1: Starting
bird: direct1: Connected to table master
bird: direct1: State changed to feed
bird: Mesh_172_23_2_30: Starting
bird: Mesh_172_23_2_30: State changed to start
bird: Mesh_172_23_2_42: Starting
bird: Mesh_172_23_2_42: State changed to start
bird: Mesh_172_23_2_170: Starting
bird: Mesh_172_23_2_170: State changed to start
bird: Mesh_172_23_2_70: Starting
bird: Mesh_172_23_2_70: State changed to start
bird: Graceful restart started
bird: Started
bird: device1: State changed to up
bird: direct1: State changed to up
bird: device1: Initializing
bird: direct1: Initializing
bird: device1: Starting
bird: device1: Connected to table master
bird: device1: State changed to feed
bird: direct1: Starting
bird: direct1: Connected to table master
bird: direct1: State changed to feed
bird: Graceful restart started
bird: Graceful restart done
bird: Started
bird: device1: State changed to up
bird: direct1: State changed to up
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Skipping confd config file.
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Backend set to etcd
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Starting confd
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Backend source(s) set to https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resources from confdir /etc/calico/confd
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird.toml.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird.toml.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird6.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird6.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird6.toml.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird6.toml.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird6_aggr.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird6_aggr.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird6_ipam.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird6_ipam.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird_aggr.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird_aggr.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/bird_ipam.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/bird_ipam.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/custom_filters.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/custom_filters.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/custom_filters6.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/custom_filters6.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Found template: /etc/calico/confd/conf.d/tunl-ip.toml
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Loading template resource from /etc/calico/confd/conf.d/tunl-ip.toml
2017-11-30 09:14:15.324 [INFO][87] logutils.go 83: Early screen log level set to info
2017-11-30 09:14:15.334 [INFO][87] felix.go 137: Felix starting up GOMAXPROCS=2 buildDate="2017-10-16T09:50:20+0000" gitCommit="64caa62946234549e6a77e622da8a0c66fc9582e" version="2.6.0"
2017-11-30 09:14:15.335 [INFO][87] felix.go 138: Command line arguments: map[--config-file:/etc/calico/felix.cfg --version:false]
2017-11-30 09:14:15.335 [INFO][87] felix.go 143: Loading configuration...
2017-11-30 09:14:15.336 [INFO][87] env_var_loader.go 41: Found felix environment variable: "felixhostname"="master-w3p6j-3696049930-sqgh9"
2017-11-30 09:14:15.337 [INFO][87] env_var_loader.go 41: Found felix environment variable: "ipv6support"="false"
2017-11-30 09:14:15.337 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdcertfile"="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.338 [INFO][87] env_var_loader.go 41: Found felix environment variable: "logseverityscreen"="info"
2017-11-30 09:14:15.338 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdscheme"=""
2017-11-30 09:14:15.339 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdaddr"=""
2017-11-30 09:14:15.339 [INFO][87] env_var_loader.go 41: Found felix environment variable: "defaultendpointtohostaction"="ACCEPT"
2017-11-30 09:14:15.339 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdkeyfile"="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.339 [INFO][87] env_var_loader.go 41: Found felix environment variable: "healthenabled"="true"
2017-11-30 09:14:15.340 [INFO][87] env_var_loader.go 41: Found felix environment variable: "ipinipmtu"="1440"
2017-11-30 09:14:15.340 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdendpoints"="https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443"
2017-11-30 09:14:15.340 [INFO][87] env_var_loader.go 41: Found felix environment variable: "etcdcafile"="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.340 [INFO][87] config_params.go 195: Merging in config from environment variable: map[etcdcertfile:/etc/kubernetes/ssl/etcd/client-crt.pem logseverityscreen:info etcdaddr: etcdkeyfile:/etc/kubernetes/ssl/etcd/client-key.pem healthenabled:true etcdcafile:/etc/kubernetes/ssl/etcd/client-ca.pem felixhostname:master-w3p6j-3696049930-sqgh9 etcdscheme: defaultendpointtohostaction:ACCEPT ipinipmtu:1440 etcdendpoints:https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 ipv6support:false]
2017-11-30 09:14:15.341 [INFO][87] config_params.go 205: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdscheme" source=environment variable
2017-11-30 09:14:15.341 [INFO][87] config_params.go 205: Ignoring empty configuration parameter. Use value 'none' if your intention is to explicitly disable the default value. name="etcdaddr" source=environment variable
2017-11-30 09:14:15.341 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.341 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.341 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.341 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.341 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.342 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.342 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.342 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 195: Merging in config from config file: map[MetadataAddr:None LogFilePath:None LogSeverityFile:None LogSeveritySys:None]
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.344 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.345 [INFO][87] config_params.go 301: Parsing value for LogSeverityFile: None (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.346 [INFO][87] config_params.go 337: Parsed value for LogSeverityFile:  (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 301: Parsing value for LogSeveritySys: None (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.346 [INFO][87] config_params.go 337: Parsed value for LogSeveritySys:  (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 301: Parsing value for MetadataAddr: None (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.346 [INFO][87] config_params.go 337: Parsed value for MetadataAddr:  (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 301: Parsing value for LogFilePath: None (from config file)
2017-11-30 09:14:15.346 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.346 [INFO][87] config_params.go 337: Parsed value for LogFilePath:  (from config file)
2017-11-30 09:14:15.356630 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-11-30 09:14:15.362 [INFO][87] felix.go 646: Waiting for the datastore to be ready
2017-11-30 09:14:15.430 [INFO][87] felix.go 657: Loading global config from datastore
2017-11-30 09:14:15.436 [INFO][87] felix.go 671: Loading per-host config from datastore; hostname=master-w3p6j-3696049930-sqgh9
2017-11-30 09:14:15.448 [INFO][87] felix.go 685: Loaded config from datastore
2017-11-30 09:14:15.448 [INFO][87] config_params.go 195: Merging in config from datastore (global): map[CalicoVersion:v2.6.2 ClusterGUID:ade2b85452dd410caea41df3a85ffd57 ClusterType:k8s,bgp IpInIpEnabled:true LogSeverityScreen:info ReportingIntervalSecs:0]
2017-11-30 09:14:15.448 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.448 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.448 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogSeverityFile: None (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogSeverityFile:  (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogSeveritySys: None (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogSeveritySys:  (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for MetadataAddr: None (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for MetadataAddr:  (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogFilePath: None (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogFilePath:  (from config file)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 341: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.449 [INFO][87] config_params.go 195: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:RETURN IpInIpTunnelAddr:192.168.24.128]
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.449 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for LogFilePath: None (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for LogFilePath:  (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for LogSeverityFile: None (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for LogSeverityFile:  (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for LogSeveritySys: None (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for LogSeveritySys:  (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for MetadataAddr: None (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for MetadataAddr:  (from config file)
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 341: Skipping config value for DefaultEndpointToHostAction from datastore (per-host); already have a value from environment variable
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 341: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 301: Parsing value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.450 [INFO][87] config_params.go 337: Parsed value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.451421 I | warning: ignoring ServerName for user-provided CA for backwards compatibility is deprecated
2017-11-30 09:14:15.451 [INFO][87] felix.go 228: Successfully loaded configuration. GOMAXPROCS=2 buildDate="2017-10-16T09:50:20+0000" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv2", FelixHostname:"master-w3p6j-3696049930-sqgh9", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/etc/kubernetes/ssl/etcd/client-key.pem", EtcdCertFile:"/etc/kubernetes/ssl/etcd/client-crt.pem", EtcdCaFile:"/etc/kubernetes/ssl/etcd/client-ca.pem", EtcdEndpoints:[]string{"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, Ipv6Support:false, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", ChainInsertMode:"insert", DefaultEndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:true, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xc0, 0xa8, 0x18, 0x80}, ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xff000000, DisableConntrackInvalidCheck:false, HealthEnabled:true, HealthPort:9099, PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0xfa1}, config.ProtoPort{Protocol:"tcp", Port:0x1b59}, config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}}, UsageReportingEnabled:true, ClusterGUID:"ade2b85452dd410caea41df3a85ffd57", ClusterType:"k8s,bgp", CalicoVersion:"v2.6.2", DebugMemoryProfilePath:"", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, sourceToRawConfig:map[config.Source]map[string]string{0x4:map[string]string{"ipv6support":"false", "defaultendpointtohostaction":"ACCEPT", "ipinipmtu":"1440", "etcdendpoints":"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443", "etcdcertfile":"/etc/kubernetes/ssl/etcd/client-crt.pem", "etcdcafile":"/etc/kubernetes/ssl/etcd/client-ca.pem", "felixhostname":"master-w3p6j-3696049930-sqgh9", "logseverityscreen":"info", "etcdkeyfile":"/etc/kubernetes/ssl/etcd/client-key.pem", "healthenabled":"true"}, 0x3:map[string]string{"LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None"}, 0x1:map[string]string{"CalicoVersion":"v2.6.2", "ClusterGUID":"ade2b85452dd410caea41df3a85ffd57", "ClusterType":"k8s,bgp", "IpInIpEnabled":"true", "LogSeverityScreen":"info", "ReportingIntervalSecs":"0"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"RETURN", "IpInIpTunnelAddr":"192.168.24.128"}}, rawValues:map[string]string{"EtcdKeyFile":"/etc/kubernetes/ssl/etcd/client-key.pem", "HealthEnabled":"true", "DefaultEndpointToHostAction":"ACCEPT", "IpInIpMtu":"1440", "EtcdCertFile":"/etc/kubernetes/ssl/etcd/client-crt.pem", "IpInIpTunnelAddr":"192.168.24.128", "ClusterType":"k8s,bgp", "FelixHostname":"master-w3p6j-3696049930-sqgh9", "Ipv6Support":"false", "LogSeveritySys":"None", "CalicoVersion":"v2.6.2", "EtcdCaFile":"/etc/kubernetes/ssl/etcd/client-ca.pem", "LogFilePath":"None", "LogSeverityScreen":"info", "EtcdEndpoints":"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443", "LogSeverityFile":"None", "MetadataAddr":"None", "IpInIpEnabled":"true", "ReportingIntervalSecs":"0", "ClusterGUID":"ade2b85452dd410caea41df3a85ffd57"}, Err:error(nil), numIptablesBitsAllocated:0} gitCommit="64caa62946234549e6a77e622da8a0c66fc9582e" version="2.6.0"
2017-11-30 09:14:15.452 [INFO][87] felix.go 238: Using internal dataplane driver.
2017-11-30 09:14:15.452 [INFO][87] felix.go 251: Calculated iptables mark bits acceptMark=0x1000000 passMark=0x2000000 scratch0Mark=0x4000000 scratch1Mark=0x8000000
2017-11-30 09:14:15.452 [INFO][87] int_dataplane.go 205: Creating internal dataplane driver. config=intdataplane.Config{IPv6Enabled:false, RuleRendererOverride:rules.RuleRenderer(nil), IPIPMTU:1440, IgnoreLooseRPF:false, MaxIPSetSize:1048576, IPSetsRefreshInterval:10000000000, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckInterval:1000000000, IptablesInsertMode:"insert", IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeout:0, IptablesLockProbeInterval:50000000, NetlinkTimeout:10000000000, RulesConfig:rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4203a1db0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4203a1ea0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x1000000, IptablesMarkPass:0x2000000, IptablesMarkScratch0:0x4000000, IptablesMarkScratch1:0x8000000, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, IPIPEnabled:true, IPIPTunnelAddress:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xc0, 0xa8, 0x18, 0x80}, IptablesLogPrefix:"calico-packet", EndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0xfa1}, config.ProtoPort{Protocol:"tcp", Port:0x1b59}, config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}}, DisableConntrackInvalid:false}, StatusReportingInterval:0, PostInSyncCallback:(func())(0x141b8c0), HealthAggregator:(*health.HealthAggregator)(0xc42037be70), DebugSimulateDataplaneHangAfter:0}
2017-11-30 09:14:15.452 [INFO][87] rule_defs.go 251: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4203a1db0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4203a1ea0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x1000000, IptablesMarkPass:0x2000000, IptablesMarkScratch0:0x4000000, IptablesMarkScratch1:0x8000000, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, IPIPEnabled:true, IPIPTunnelAddress:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xc0, 0xa8, 0x18, 0x80}, IptablesLogPrefix:"calico-packet", EndpointToHostAction:"ACCEPT", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0xfa1}, config.ProtoPort{Protocol:"tcp", Port:0x1b59}, config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}}, DisableConntrackInvalid:false}
2017-11-30 09:14:15.452 [INFO][87] rule_defs.go 261: Workload to host packets will be accepted.
2017-11-30 09:14:15.452 [INFO][87] rule_defs.go 275: filter table allowed packets will be accepted immediately.
2017-11-30 09:14:15.452 [INFO][87] rule_defs.go 283: mangle table allowed packets will be accepted immediately.
2017-11-30 09:14:15.452 [INFO][87] int_dataplane.go 240: iptables lock disabled.
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1/global/custom_filters
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1/global
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/v1/ipam/v6
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1/global
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/ipam/v2/host/master-w3p6j-3696049930-sqgh9/ipv4/block
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/v1/ipam/v4
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/ipam/v2/host/master-w3p6j-3696049930-sqgh9/ipv6/block
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30 09:14:15.460 [INFO][87] route_table.go 134: Calculated interface name regexp regex="^cali.*"
2017-11-30 09:14:15.460 [INFO][87] ipsets.go 116: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2017-11-30 09:14:15.460 [INFO][87] ipsets.go 116: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2017-11-30 09:14:15.461 [INFO][87] int_dataplane.go 382: Registering to report health.
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.461 [INFO][87] int_dataplane.go 506: IPIP enabled, starting thread to keep tunnel configuration in sync.
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2017-11-30 09:14:15.461 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2017-11-30 09:14:15.461 [INFO][87] felix.go 322: Connect to the dataplane driver.
2017-11-30 09:14:15.464 [INFO][87] ipip_mgr.go 77: IPIP thread started.
2017-11-30 09:14:15.464 [INFO][87] ipip_mgr.go 98: Failed to get IPIP tunnel device, assuming it isn't present error=Link not found
2017-11-30 09:14:15.465 [INFO][87] iface_monitor.go 73: Interface monitoring thread started.
2017-11-30 09:14:15.473 [INFO][87] int_dataplane.go 537: Started internal iptables dataplane driver loop
2017-11-30 09:14:15.475 [INFO][87] int_dataplane.go 548: Will refresh IP sets on timer interval=1m30s
2017-11-30 09:14:15.475 [INFO][87] int_dataplane.go 558: Will refresh routes on timer interval=1m30s
2017-11-30 09:14:15.476 [INFO][87] int_dataplane.go 920: Started internal status report thread
2017-11-30 09:14:15.476 [INFO][87] int_dataplane.go 922: Process status reports disabled
2017-11-30 09:14:15.461 [INFO][87] felix.go 362: Created Syncer syncer=&etcd.etcdSyncer{callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42000c1b8), keysAPI:(*client.httpKeysAPI)(0xc42055a160), OneShot:false}
2017-11-30 09:14:15.484 [INFO][87] calc_graph.go 87: Creating calculation graph, filtered to hostname master-w3p6j-3696049930-sqgh9
2017-11-30 09:14:15.484 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1352250)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1352250)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1352310)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1352310)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x1352140)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x11dc7c0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x11dc7c0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x11dc7c0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x11dc7c0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1352500)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1352500)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x1352570)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x1352570)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x1352570)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x1352440)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x1352440)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x1352380)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x1352380)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x1352380)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x13526a0)
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x13526a0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x13526a0)
2017-11-30 09:14:15.485 [INFO][87] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x13526a0)
2017-11-30 09:14:15.485 [INFO][87] felix.go 426: Starting the datastore Syncer
2017-11-30 09:14:15.485 [INFO][87] syncer.go 132: Starting etcd Syncer
2017-11-30 09:14:15.490 [INFO][87] syncer.go 149: Syncer not in one-shot mode, starting watcher thread
2017-11-30 09:14:15.490 [INFO][87] async_calc_graph.go 227: Starting AsyncCalcGraph
2017-11-30 09:14:15.490 [INFO][87] felix.go 441: Started the processing graph
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1/global/custom_filters
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6.toml.template
2017-11-30 09:14:15.500 [INFO][87] syncer.go 366: Cluster ID poll thread started
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6.toml.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/conf.d/bird6.toml
2017-11-30 09:14:15.501 [INFO][87] iface_monitor.go 80: Subscribed to netlink updates.
2017-11-30 09:14:15.501 [INFO][87] int_dataplane.go 429: Linux interface state changed. ifaceName="lo" state="up"
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 447: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 429: Linux interface state changed. ifaceName="eth0" state="up"
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 447: Linux interface addrs changed. addrs=set.mapSet{"172.23.2.38":set.empty{}, "fe80::dcad:beff:fe39:4ba":set.empty{}} ifaceName="eth0"
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 447: Linux interface addrs changed. addrs=set.mapSet{"172.17.0.1":set.empty{}} ifaceName="docker0"
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 588: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 588: Received interface update msg=&intdataplane.ifaceUpdate{Name:"eth0", State:"up"}
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 598: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 598: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"eth0", Addrs:set.mapSet{"172.23.2.38":set.empty{}, "fe80::dcad:beff:fe39:4ba":set.empty{}}}
2017-11-30 09:14:15.502 [INFO][87] int_dataplane.go 598: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"docker0", Addrs:set.mapSet{"172.17.0.1":set.empty{}}}
2017-11-30 09:14:15.505 [INFO][87] usagerep.go 38: Usage reporting thread started, waiting for size estimate
2017-11-30 09:14:15.505 [INFO][87] syncer.go 247: etcd watch thread started.
2017-11-30 09:14:15.504 [INFO][87] syncer.go 170: Syncer snapshot-reading thread started
2017-11-30 09:14:15.505 [INFO][87] async_calc_graph.go 133: AsyncCalcGraph running
2017-11-30 09:14:15.505 [INFO][87] felix.go 818: Possible config update new=map[string]string{"EtcdCaFile":"/etc/kubernetes/ssl/etcd/client-ca.pem", "LogFilePath":"None", "LogSeverityScreen":"info", "EtcdEndpoints":"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443", "LogSeverityFile":"None", "MetadataAddr":"None", "IpInIpEnabled":"true", "ReportingIntervalSecs":"0", "ClusterGUID":"ade2b85452dd410caea41df3a85ffd57", "EtcdKeyFile":"/etc/kubernetes/ssl/etcd/client-key.pem", "HealthEnabled":"true", "DefaultEndpointToHostAction":"ACCEPT", "IpInIpMtu":"1440", "EtcdCertFile":"/etc/kubernetes/ssl/etcd/client-crt.pem", "IpInIpTunnelAddr":"192.168.24.128", "ClusterType":"k8s,bgp", "FelixHostname":"master-w3p6j-3696049930-sqgh9", "Ipv6Support":"false", "LogSeveritySys":"None", "CalicoVersion":"v2.6.2"} old=map[string]string(nil)
2017-11-30 09:14:15.506 [INFO][87] felix.go 823: Config resolved. new=map[string]string{"MetadataAddr":"None", "IpInIpEnabled":"true", "ReportingIntervalSecs":"0", "ClusterGUID":"ade2b85452dd410caea41df3a85ffd57", "LogSeverityScreen":"info", "EtcdEndpoints":"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443", "LogSeverityFile":"None", "IpInIpMtu":"1440", "EtcdCertFile":"/etc/kubernetes/ssl/etcd/client-crt.pem", "IpInIpTunnelAddr":"192.168.24.128", "ClusterType":"k8s,bgp", "EtcdKeyFile":"/etc/kubernetes/ssl/etcd/client-key.pem", "HealthEnabled":"true", "DefaultEndpointToHostAction":"ACCEPT", "CalicoVersion":"v2.6.2", "FelixHostname":"master-w3p6j-3696049930-sqgh9", "Ipv6Support":"false", "LogSeveritySys":"None", "EtcdCaFile":"/etc/kubernetes/ssl/etcd/client-ca.pem", "LogFilePath":"None"} old=map[string]string(nil)
2017-11-30 09:14:15.513 [INFO][87] int_dataplane.go 574: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v2.6.2" > config:<key:"ClusterGUID" value:"ade2b85452dd410caea41df3a85ffd57" > config:<key:"ClusterType" value:"k8s,bgp" > config:<key:"DefaultEndpointToHostAction" value:"ACCEPT" > config:<key:"EtcdCaFile" value:"/etc/kubernetes/ssl/etcd/client-ca.pem" > config:<key:"EtcdCertFile" value:"/etc/kubernetes/ssl/etcd/client-crt.pem" > config:<key:"EtcdEndpoints" value:"https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443" > config:<key:"EtcdKeyFile" value:"/etc/kubernetes/ssl/etcd/client-key.pem" > config:<key:"FelixHostname" value:"master-w3p6j-3696049930-sqgh9" > config:<key:"HealthEnabled" value:"true" > config:<key:"IpInIpEnabled" value:"true" > config:<key:"IpInIpMtu" value:"1440" > config:<key:"IpInIpTunnelAddr" value:"192.168.24.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" > 
2017-11-30 09:14:15.522 [INFO][87] felix.go 480: Health enabled.  Starting server. port=9099
2017-11-30 09:14:15.523 [INFO][87] health.go 144: Starting health endpoints port=9099
2017-11-30 09:14:15.504 [INFO][87] felix.go 735: Reading from dataplane driver pipe...
2017-11-30 09:14:15.524 [INFO][87] int_dataplane.go 447: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="tunl0"
2017-11-30 09:14:15.524 [INFO][87] int_dataplane.go 598: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{}}
2017-11-30 09:14:15.524 [INFO][87] felix.go 570: No driver process to monitor
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird.toml.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird.toml.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/conf.d/bird.toml
2017-11-30 09:14:15.534 [WARNING][87] ipip_mgr.go 104: Failed to add IPIP tunnel device error=exit status 1
2017-11-30 09:14:15.534 [WARNING][87] ipip_mgr.go 81: Failed configure IPIP tunnel device, retrying... error=exit status 1
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/conf.d/bird.toml in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/conf.d/bird6.toml in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6_ipam.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6_ipam.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6_ipam.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6_ipam.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/custom_filters6.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/custom_filters6.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/custom_filters6.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/custom_filters6.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/tunl-ip.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/tunl-ip.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird_aggr.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird_aggr.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6_aggr.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6_aggr.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /tmp/tunl-ip
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /tmp/tunl-ip in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/custom_filters.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/custom_filters.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/custom_filters.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/custom_filters.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird_aggr.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird_aggr.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird_aggr.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird_aggr.cfg in sync
2017-11-30 09:14:15.825 [INFO][87] syncer.go 377: etcd cluster ID now known clusterID="9c639bd788659d31"
2017-11-30 09:14:15.827 [INFO][87] syncer.go 262: Polled etcd for initial watch index. index=0x6b
2017-11-30 09:14:15.828 [INFO][87] syncer.go 469: Watcher out-of-sync, starting to track deletions
2017-11-30 09:14:15.828 [INFO][87] syncer.go 508: Watcher is out-of-sync but no snapshot in progress, starting one.
2017-11-30 09:14:15.828 [INFO][87] syncer.go 179: Asked for new snapshot newMinIndex=0x6b
2017-11-30 09:14:15.828 [INFO][87] syncer.go 188: Newest snapshot is too stale, loading a new one currentIdx=0x0 requiredIdx=0x6b
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird_ipam.cfg.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird_ipam.cfg.template
2017-11-30 09:14:15.833 [INFO][87] syncer.go 473: Started receiving snapshot snapshotIndex=0x6b
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v2.6.2 101 0s} 1}
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=ClusterGUID) ade2b85452dd410caea41df3a85ffd57 5 0s} 1}
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 17 0s} 1}
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=IpInIpEnabled) true 12 0s} 1}
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) info 14 0s} 1}
2017-11-30 09:14:15.834 [INFO][87] config_batcher.go 70: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 13 0s} 1}
2017-11-30 09:14:15.838 [INFO][87] config_batcher.go 60: Host config update for this host: {{HostConfig(node=master-w3p6j-3696049930-sqgh9,name=DefaultEndpointToHostAction) RETURN 100 0s} 1}
2017-11-30 09:14:15.838 [INFO][87] config_batcher.go 60: Host config update for this host: {{HostConfig(node=master-w3p6j-3696049930-sqgh9,name=IpInIpTunnelAddr) 192.168.24.128 107 0s} 1}
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird_ipam.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird_ipam.cfg in sync
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30 09:14:15.843 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"worker-s1rnj-504333212-wjgw3" ipv4_addr:"172.23.2.70" 
2017-11-30 09:14:15.847 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"master-w3p6j-3696049930-sqgh9" ipv4_addr:"172.23.2.38" 
2017-11-30 09:14:15.847 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"master-w3p6j-3696049930-jb3sn" ipv4_addr:"172.23.2.30" 
2017-11-30 09:14:15.851 [INFO][87] syncer.go 482: Finished receiving snapshot, cleaning up old keys. minSnapshotIndex=0x6b snapshotIndex=0x6b
2017-11-30 09:14:15.852 [INFO][87] syncer.go 487: Deleted old keys that weren't seen in snapshot. minSnapshotIndex=0x6b numDeletedKeys=0 snapshotIndex=0x6b
2017-11-30 09:14:15.852 [INFO][87] syncer.go 495: Snapshot brought us into sync. minSnapshotIndex=0x6b snapshotIndex=0x6b
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird.cfg
2017-11-30T09:14:15Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird.cfg in sync
2017-11-30 09:14:15.852 [INFO][87] config_batcher.go 97: Datamodel in sync, flushing config update
2017-11-30 09:14:15.852 [INFO][87] config_batcher.go 108: Sending config update global: map[ReportingIntervalSecs:0 CalicoVersion:v2.6.2 ClusterGUID:ade2b85452dd410caea41df3a85ffd57 ClusterType:k8s,bgp IpInIpEnabled:true LogSeverityScreen:info], host: map[DefaultEndpointToHostAction:RETURN IpInIpTunnelAddr:192.168.24.128].
2017-11-30 09:14:15.852 [INFO][87] async_calc_graph.go 160: First time we've been in sync
2017-11-30 09:14:15.852 [INFO][87] event_sequencer.go 192: Possible config update. global=map[string]string{"ReportingIntervalSecs":"0", "CalicoVersion":"v2.6.2", "ClusterGUID":"ade2b85452dd410caea41df3a85ffd57", "ClusterType":"k8s,bgp", "IpInIpEnabled":"true", "LogSeverityScreen":"info"} host=map[string]string{"DefaultEndpointToHostAction":"RETURN", "IpInIpTunnelAddr":"192.168.24.128"}
2017-11-30 09:14:15.852 [INFO][87] config_params.go 195: Merging in config from datastore (global): map[ReportingIntervalSecs:0 CalicoVersion:v2.6.2 ClusterGUID:ade2b85452dd410caea41df3a85ffd57 ClusterType:k8s,bgp IpInIpEnabled:true LogSeverityScreen:info]
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for LogSeverityFile: None (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for LogSeverityFile:  (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for LogSeveritySys: None (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for LogSeveritySys:  (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for MetadataAddr: None (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for MetadataAddr:  (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for LogFilePath: None (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for LogFilePath:  (from config file)
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.852 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.852 [INFO][87] config_params.go 341: Skipping config value for DefaultEndpointToHostAction from datastore (per-host); already have a value from environment variable
2017-11-30 09:14:15.852 [INFO][87] config_params.go 301: Parsing value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for CalicoVersion: v2.6.2 (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for IpInIpEnabled: true (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 341: Skipping config value for LogSeverityScreen from datastore (global); already have a value from environment variable
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2017-11-30 09:14:15.853 [INFO][87] config_params.go 195: Merging in config from datastore (per-host): map[IpInIpTunnelAddr:192.168.24.128 DefaultEndpointToHostAction:RETURN]
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for LogSeverityScreen: info (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for LogSeverityScreen: INFO (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-key.pem"
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for EtcdKeyFile: /etc/kubernetes/ssl/etcd/client-key.pem (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for HealthEnabled: true (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for FelixHostname: master-w3p6j-3696049930-sqgh9 (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: ACCEPT (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for IpInIpMtu: 1440 (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for EtcdEndpoints: https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443 (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for EtcdEndpoints: [https://etcd.fz8zh.g8s.geckon.gridscale.kvm.gigantic.io:443/] (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-crt.pem"
2017-11-30 09:14:15.853 [INFO][87] config_params.go 337: Parsed value for EtcdCertFile: /etc/kubernetes/ssl/etcd/client-crt.pem (from environment variable)
2017-11-30 09:14:15.853 [INFO][87] config_params.go 301: Parsing value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.856 [INFO][87] param_types.go 217: Looking for required file path="/etc/kubernetes/ssl/etcd/client-ca.pem"
2017-11-30 09:14:15.856 [INFO][87] config_params.go 337: Parsed value for EtcdCaFile: /etc/kubernetes/ssl/etcd/client-ca.pem (from environment variable)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for Ipv6Support: false (from environment variable)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for LogFilePath: None (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for LogFilePath:  (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for LogSeverityFile: None (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for LogSeverityFile:  (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for LogSeveritySys: None (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for LogSeveritySys:  (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for MetadataAddr: None (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 318: Value set to 'none', replacing with zero-value: "".
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for MetadataAddr:  (from config file)
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for IpInIpTunnelAddr: 192.168.24.128 (from datastore (per-host))
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2017-11-30 09:14:15.857 [INFO][87] config_params.go 341: Skipping config value for DefaultEndpointToHostAction from datastore (per-host); already have a value from environment variable
2017-11-30 09:14:15.857 [INFO][87] config_params.go 301: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2017-11-30 09:14:15.857 [INFO][87] config_params.go 337: Parsed value for ClusterType: k8s,bgp (from datastore (global))
... dropped 9 logs ...
2017-11-30 09:14:15.858 [INFO][87] config_params.go 301: Parsing value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.858 [INFO][87] config_params.go 337: Parsed value for ClusterGUID: ade2b85452dd410caea41df3a85ffd57 (from datastore (global))
2017-11-30 09:14:15.858 [INFO][87] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"worker-iy4mr-2056238832-1prmw" ipv4_addr:"172.23.2.42" 
2017-11-30 09:14:15.858 [INFO][87] usagerep.go 40: Initial stats read stats=calc.StatsUpdate{NumHosts:5, NumWorkloadEndpoints:5, NumHostEndpoints:0}
2017-11-30 09:14:15.858 [INFO][87] usagerep.go 44: Waiting before first check-in delay=5m4.099s
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"worker-kn6bo-3121522012-33blp" ipv4_addr:"172.23.2.170" 
2017-11-30 09:14:15.858 [INFO][87] felix.go 807: Datastore now in sync.
2017-11-30 09:14:15.858 [INFO][87] felix.go 809: Datastore in sync for first time, sending message to status reporter.
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 574: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"192.168.0.0-16" pool:<cidr:"192.168.0.0/16" masquerade:true > 
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 574: Received *proto.InSync update from calculation graph msg=
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 582: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=534.257321ms
2017-11-30 09:14:15.858 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:15.858 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.859 [INFO][87] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2017-11-30 09:14:15.859 [INFO][87] table.go 398: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2017-11-30 09:14:15.859 [INFO][87] ipip_mgr.go 214: All-hosts IP set out-of sync, refreshing it.
2017-11-30 09:14:15.859 [INFO][87] ipsets.go 116: Queueing IP set for creation family="inet" setID="all-hosts" setType="hash:ip"
2017-11-30 09:14:15.859 [INFO][87] route_table.go 200: Trying to connect to netlink
2017-11-30 09:14:15.859 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:14:15.884 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=25.05698ms
2017-11-30 09:14:15.885 [INFO][87] ipsets.go 685: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2017-11-30 09:14:15.886 [INFO][87] ipsets.go 685: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2017-11-30 09:14:15.886 [INFO][87] ipsets.go 685: Doing full IP set rewrite family="inet" numMembersInPendingReplace=5 setID="all-hosts"
2017-11-30 09:14:15.920 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:15.920 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:15.920 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:15.920 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:15.963 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=105.252644
2017-11-30 09:14:15.963 [INFO][87] int_dataplane.go 710: Completed first update to dataplane. secsSinceStart=0.63969423
bird: Mesh_172_23_2_42: Connected to table master
bird: Mesh_172_23_2_42: State changed to wait
2017-11-30 09:14:16.534 [INFO][87] ipip_mgr.go 117: Tunnel device MTU needs to be updated mtu=1440 oldMTU=1480 tunnelAddr=192.168.24.128
2017-11-30 09:14:16.535 [INFO][87] ipip_mgr.go 122: Updated tunnel MTU mtu=1440 tunnelAddr=192.168.24.128
2017-11-30 09:14:16.535 [INFO][87] ipip_mgr.go 125: Tunnel wasn't admin up, enabling it flags=0 mtu=1440 tunnelAddr=192.168.24.128
2017-11-30 09:14:16.536 [INFO][87] ipip_mgr.go 130: Set tunnel admin up mtu=1440 tunnelAddr=192.168.24.128
2017-11-30 09:14:16.536 [INFO][87] ipip_mgr.go 175: Address wasn't present, adding it. addr=192.168.24.128 link="tunl0"
2017-11-30 09:14:16.536 [INFO][87] int_dataplane.go 429: Linux interface state changed. ifaceName="tunl0" state="up"
2017-11-30 09:14:16.536 [INFO][87] int_dataplane.go 447: Linux interface addrs changed. addrs=set.mapSet{"192.168.24.128":set.empty{}} ifaceName="tunl0"
2017-11-30 09:14:16.536 [INFO][87] iface_monitor.go 143: Netlink address update. addr="192.168.24.128" exists=true ifIndex=4
2017-11-30 09:14:16.536 [INFO][87] int_dataplane.go 588: Received interface update msg=&intdataplane.ifaceUpdate{Name:"tunl0", State:"up"}
2017-11-30 09:14:16.536 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:16.537 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=0.243389
2017-11-30 09:14:16.537 [INFO][87] int_dataplane.go 598: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"tunl0", Addrs:set.mapSet{"192.168.24.128":set.empty{}}}
2017-11-30 09:14:16.537 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:16.537 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=0.122663
2017-11-30 09:14:16.958 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:16.958 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:16.958 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:16.964 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=5.239643
2017-11-30 09:14:16.967 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:16.967 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:16.967 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:16.967 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:16.967 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:16.968 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:16.968 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:16.978 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=10.930515
2017-11-30 09:14:17.968 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:17.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:17.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:17.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:17.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:17.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:17.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:17.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:17.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:17.992 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=23.899923
bird: Mesh_172_23_2_70: Connected to table master
bird: Mesh_172_23_2_70: State changed to wait
2017-11-30 09:14:19.982 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:19.982 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:19.982 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:19.982 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:19.982 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:19.983 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:19.983 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:19.983 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:19.983 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:19.993 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=11.788068
2017-11-30 09:14:23.969 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:23.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:23.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:23.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:23.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:23.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:23.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:23.970 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:23.970 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:23.985 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=16.235902
2017-11-30 09:14:26.200 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:26.200 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:14:26.200 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:14:26.206 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=6.001879ms
2017-11-30 09:14:26.207 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=7.017159
2017-11-30 09:14:27.322 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:31.959 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:31.959 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:31.959 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:31.960 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.877487
2017-11-30 09:14:31.962 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:31.962 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:31.962 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:31.964 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.191583
2017-11-30 09:14:31.966 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:31.973 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:31.974 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:31.982 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:31.982 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:31.985 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=18.801063
2017-11-30 09:14:32.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:36.519 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:36.519 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:14:36.520 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:14:36.525 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=5.148801ms
2017-11-30 09:14:36.526 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=6.563395
2017-11-30 09:14:37.321 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:42.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:47.322 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:47.353 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:47.353 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:14:47.353 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:14:47.356 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.155795ms
2017-11-30 09:14:47.356 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.6887399999999997
2017-11-30 09:14:47.958 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:47.959 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:14:47.959 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:14:47.968 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=9.185291999999999
2017-11-30 09:14:47.969 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:47.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:14:47.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:14:47.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:14:47.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:14:47.969 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:14:47.969 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:14:48.001 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=31.767291000000004
2017-11-30 09:14:52.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:57.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:14:57.635 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:14:57.635 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:14:57.635 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:14:57.636 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.736646ms
2017-11-30 09:14:57.637 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.995804
2017-11-30 09:15:02.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:07.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:08.337 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:08.337 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:15:08.337 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:15:08.339 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.167778ms
2017-11-30 09:15:08.339 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.6200289999999997
2017-11-30 09:15:12.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:17.322 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:18.873 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:18.874 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:15:18.874 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:15:18.876 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.939473ms
2017-11-30 09:15:18.876 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.364735
2017-11-30 09:15:19.958 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:19.959 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:15:19.959 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:15:19.961 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.1935819999999997
2017-11-30 09:15:19.962 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:19.962 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:15:19.962 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:15:19.964 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.595289
2017-11-30 09:15:19.964 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:19.965 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:15:19.965 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:15:19.965 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:15:19.965 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:15:19.982 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=16.981741000000003
2017-11-30 09:15:22.048 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:27.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:29.054 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:29.054 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:15:29.055 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:15:29.057 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.037598ms
2017-11-30 09:15:29.057 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.606311
2017-11-30 09:15:32.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:37.325 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:39.730 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:39.730 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:15:39.730 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:15:39.732 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.750222ms
2017-11-30 09:15:39.733 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.226019
2017-11-30 09:15:42.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:46.367 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:46.367 [INFO][87] route_table.go 190: Queueing a resync of routing table. ipVersion=0x4
2017-11-30 09:15:46.367 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=0.5225139999999999
2017-11-30 09:15:47.321 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:50.409 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:15:50.409 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:15:50.409 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:15:50.410 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.610778ms
2017-11-30 09:15:50.411 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.8289650000000002
2017-11-30 09:15:52.050 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:15:57.325 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:00.498 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:00.498 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:00.498 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:00.500 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.484774ms
2017-11-30 09:16:00.500 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.727145
2017-11-30 09:16:02.045 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:07.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:10.933 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:10.934 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:10.934 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:10.940 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=6.800314ms
2017-11-30 09:16:10.941 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=7.075392
2017-11-30 09:16:12.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:17.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:21.377 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:21.377 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:21.377 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:21.379 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.683448ms
2017-11-30 09:16:21.379 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.072159
2017-11-30 09:16:22.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:23.462 [INFO][87] int_dataplane.go 574: Received *proto.HostMetadataRemove update from calculation graph msg=hostname:"master-w3p6j-3696049930-jb3sn" 
2017-11-30 09:16:23.463 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:23.463 [INFO][87] ipip_mgr.go 214: All-hosts IP set out-of sync, refreshing it.
2017-11-30 09:16:23.463 [INFO][87] ipsets.go 116: Queueing IP set for creation family="inet" setID="all-hosts" setType="hash:ip"
2017-11-30 09:16:23.465 [INFO][87] ipsets.go 685: Doing full IP set rewrite family="inet" numMembersInPendingReplace=4 setID="all-hosts"
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30 09:16:23.474 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=11.045875
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO /etc/calico/confd/config/bird.cfg has md5sum e1cf5a19287d8ab52753d16fec95009f should be ce000438df7203ad126314f1f693dc42
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6.cfg in sync
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Target config /etc/calico/confd/config/bird.cfg out of sync
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Running bird -p -c /etc/calico/confd/config/.bird.cfg423860377
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG ""
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Overwriting target config /etc/calico/confd/config/bird.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Running pkill -HUP bird || true
bird: Reconfiguration requested by SIGHUP
bird: Reconfiguring
bird: device1: Reconfigured
bird: direct1: Reconfigured
bird: Removing protocol Mesh_172_23_2_30
bird: Mesh_172_23_2_30: Shutting down
bird: Mesh_172_23_2_30: State changed to stop
bird: Mesh_172_23_2_42: Reconfigured
bird: Mesh_172_23_2_170: Reconfigured
bird: Mesh_172_23_2_70: Reconfigured
bird: Mesh_172_23_2_30: State changed to down
bird: Reconfigured
bird: Reconfiguration requested by SIGHUP
bird: Reconfiguring
bird: device1: Reconfigured
bird: direct1: Reconfigured
bird: Reconfigured
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6.cfg in sync
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG ""
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Target config /etc/calico/confd/config/bird.cfg has been updated
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird6.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird6.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird6.cfg in sync
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO /etc/calico/confd/config/bird.cfg has md5sum ce000438df7203ad126314f1f693dc42 should be 10cd9c0551d834443a6c5d932c15e557
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Target config /etc/calico/confd/config/bird.cfg out of sync
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Running bird -p -c /etc/calico/confd/config/.bird.cfg236170742
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG ""
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Overwriting target config /etc/calico/confd/config/bird.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Running pkill -HUP bird || true
bird: Reconfiguration requested by SIGHUP
bird: Reconfiguring
bird: device1: Reconfiguredbird: Reconfiguration requested by SIGHUP
bird: Reconfiguring
bird: device1: Reconfigured
bird: direct1: Reconfigured
bird: Reconfigured

bird: direct1: Reconfigured
bird: Mesh_172_23_2_42: Reconfigured
bird: Mesh_172_23_2_170: Reconfigured
bird: Mesh_172_23_2_70: Reconfigured
bird: Reconfigured
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG ""
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: INFO Target config /etc/calico/confd/config/bird.cfg has been updated
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Retrieving keys from store
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Key prefix set to /calico/bgp/v1
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Using source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Compiling source template /etc/calico/confd/templates/bird.cfg.mesh.template
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Comparing candidate config to /etc/calico/confd/config/bird.cfg
2017-11-30T09:16:23Z master-w3p6j-3696049930-sqgh9 confd[89]: DEBUG Target config /etc/calico/confd/config/bird.cfg in sync
2017-11-30 09:16:23.958 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:23.959 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2017-11-30 09:16:23.959 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:16:23.961 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.191737
2017-11-30 09:16:23.962 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:23.962 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2017-11-30 09:16:23.962 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:16:23.964 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.6288529999999999
2017-11-30 09:16:23.965 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:23.965 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2017-11-30 09:16:23.965 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:16:23.965 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2017-11-30 09:16:23.965 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:16:23.990 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=25.799435
2017-11-30 09:16:27.322 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:31.691 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:31.691 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:31.691 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:31.693 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.862919ms
2017-11-30 09:16:31.693 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.572984
2017-11-30 09:16:32.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:37.324 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:42.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:42.604 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:42.604 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:42.604 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:42.607 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.410332ms
2017-11-30 09:16:42.607 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=3.0051409999999996
2017-11-30 09:16:47.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:52.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:16:52.777 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:16:52.777 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:16:52.777 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:16:52.779 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.826943ms
2017-11-30 09:16:52.779 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.2084029999999997
2017-11-30 09:16:57.324 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:02.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:02.860 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:02.860 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:02.860 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:02.872 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=11.710135ms
2017-11-30 09:17:02.873 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=12.472963
2017-11-30 09:17:07.321 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:12.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:13.607 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:13.607 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:13.607 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:13.609 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.560133ms
2017-11-30 09:17:13.609 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.963361
2017-11-30 09:17:17.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:22.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:22.112 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:22.112 [INFO][87] route_table.go 190: Queueing a resync of routing table. ipVersion=0x4
2017-11-30 09:17:22.112 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=0.353077
2017-11-30 09:17:23.759 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:23.759 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:23.759 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:23.760 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.628529ms
2017-11-30 09:17:23.761 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=1.91577
2017-11-30 09:17:27.331 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:32.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:33.883 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:33.884 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:33.884 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:33.888 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.472666ms
2017-11-30 09:17:33.888 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=3.89144
2017-11-30 09:17:37.322 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:42.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:44.775 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:44.775 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:44.775 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:44.780 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.870024ms
2017-11-30 09:17:44.780 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=5.285127
2017-11-30 09:17:47.320 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:52.046 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:17:53.959 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:53.959 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2017-11-30 09:17:53.959 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2017-11-30 09:17:53.963 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=3.7627260000000002
2017-11-30 09:17:53.966 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:53.966 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2017-11-30 09:17:53.966 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2017-11-30 09:17:53.966 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="nat"
2017-11-30 09:17:53.966 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2017-11-30 09:17:53.966 [INFO][87] table.go 717: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="filter"
2017-11-30 09:17:53.966 [INFO][87] table.go 438: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2017-11-30 09:17:53.974 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=8.009964
2017-11-30 09:17:55.679 [INFO][87] int_dataplane.go 690: Applying dataplane updates
2017-11-30 09:17:55.679 [INFO][87] ipsets.go 224: Asked to resync with the dataplane on next update. family="inet"
2017-11-30 09:17:55.679 [INFO][87] ipsets.go 255: Resyncing ipsets with dataplane. family="inet"
2017-11-30 09:17:55.680 [INFO][87] ipsets.go 297: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.341811ms
2017-11-30 09:17:55.681 [INFO][87] int_dataplane.go 705: Finished applying updates to dataplane. msecToApply=2.234411
2017-11-30 09:17:57.321 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}
2017-11-30 09:18:02.047 [INFO][87] health.go 121: Overall health summary=&health.HealthReport{Live:true, Ready:true}