2019-11-16 16:58:19.766 [INFO][63] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp002", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"6e78891db03e4026a7766acf3b36b7b3", ClusterType:"k8s,bgp", CalicoVersion:"v3.3.2", ExternalNodesCIDRList:[]string(nil), DebugMemoryProfilePath:"", DebugCPUProfilePath:"/tmp/felix-cpu-<timestamp>.pprof", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, sourceToRawConfig:map[config.Source]map[string]string{0x4:map[string]string{"felixhostname":"cmp002", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem"}, 0x3:map[string]string{"MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None"}, 0x1:map[string]string{"ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"FelixHostname":"cmp002", "DefaultEndpointToHostAction":"Return", "CalicoVersion":"v3.3.2", "ReportingIntervalSecs":"0", "EtcdCaFile":"/var/lib/etcd/ca.pem", "MetadataAddr":"None", "LogFilePath":"None", "LogSeverityScreen":"Info", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "LogSeverityFile":"None", "LogSeveritySys":"None", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "EtcdEndpoints":"https://172.16.10.36:4001"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-11-16 16:58:19.766 [INFO][63] driver.go 43: Using internal (linux) dataplane driver.
2019-11-16 16:58:19.766 [INFO][63] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-11-16 16:58:19.766 [INFO][63] int_dataplane.go 212: Creating internal dataplane driver. config=intdataplane.Config{IPv6Enabled:true, 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)(0xc420092a00), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc420092af0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x10000, IptablesMarkPass:0x20000, IptablesMarkScratch0:0x40000, IptablesMarkScratch1:0x80000, IptablesMarkEndpoint:0xfff00000, IptablesMarkNonCaliEndpoint:0x100000, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, KubeIPVSSupportEnabled:false, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, IPIPEnabled:false, IPIPTunnelAddress:net.IP(nil), IptablesLogPrefix:"calico-packet", EndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}}, IfaceMonitorConfig:ifacemonitor.Config{InterfaceExcludes:[]string{"kube-ipvs0"}}, StatusReportingInterval:0, ConfigChangedRestartCallback:(func())(0x1398480), PostInSyncCallback:(func())(0x137f060), HealthAggregator:(*health.HealthAggregator)(0xc4203f12e0), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-11-16 16:58:19.767 [INFO][63] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc420092a00), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc420092af0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x10000, IptablesMarkPass:0x20000, IptablesMarkScratch0:0x40000, IptablesMarkScratch1:0x80000, IptablesMarkEndpoint:0xfff00000, IptablesMarkNonCaliEndpoint:0x100000, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, KubeIPVSSupportEnabled:false, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, IPIPEnabled:false, IPIPTunnelAddress:net.IP(nil), IptablesLogPrefix:"calico-packet", EndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}}
2019-11-16 16:58:19.767 [INFO][63] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-11-16 16:58:19.767 [INFO][63] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-11-16 16:58:19.767 [INFO][63] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-11-16 16:58:19.770 [INFO][63] feature_detect.go 108: Updating detected iptables features features=iptables.Features{SNATFullyRandom:true, MASQFullyRandom:true, RestoreSupportsLock:true} iptablesVersion=1.6.2 kernelVersion=4.15.0
2019-11-16 16:58:19.773 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:19.773 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.773 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.775 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:19.775 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.775 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.776 [INFO][63] int_dataplane.go 424: Registering to report health.
2019-11-16 16:58:19.776 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.776 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.776 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.776 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.776 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.777 [INFO][63] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.777 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.777 [INFO][63] daemon.go 299: Connect to the dataplane driver.
2019-11-16 16:58:19.777 [INFO][63] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-11-16 16:58:19.777 [INFO][63] int_dataplane.go 981: Started internal status report thread
2019-11-16 16:58:19.778 [INFO][63] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-11-16 16:58:19.778 [INFO][63] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-11-16 16:58:19.777 [INFO][63] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4201aa100), (*watchersyncer.watcherCache)(0xc4201aa180), (*watchersyncer.watcherCache)(0xc4201aa280), (*watchersyncer.watcherCache)(0xc4201aa580), (*watchersyncer.watcherCache)(0xc4201aa600), (*watchersyncer.watcherCache)(0xc4201aa680), (*watchersyncer.watcherCache)(0xc4201aa700), (*watchersyncer.watcherCache)(0xc4201aa780), (*watchersyncer.watcherCache)(0xc4201ab880), (*watchersyncer.watcherCache)(0xc4201ab900)}, results:(chan interface {})(0xc42014e5a0), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42015c580), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-11-16 16:58:19.778 [INFO][63] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp002
2019-11-16 16:58:19.778 [INFO][63] iface_monitor.go 88: Interface monitoring thread started.
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:19.778 [INFO][63] iface_monitor.go 95: Subscribed to netlink updates.
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.778 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fec7:2624":set.empty{}, "192.168.11.37":set.empty{}} ifaceName="ens3"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe3d:c4b4":set.empty{}} ifaceName="ens4"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}} ifaceName="ens5"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.779 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-11-16 16:58:19.779 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe3d:c4b4":set.empty{}} ifaceName="br-mgmt"
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-11-16 16:58:19.780 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-11-16 16:58:19.780 [INFO][63] daemon.go 439: Starting the datastore Syncer
2019-11-16 16:58:19.780 [INFO][63] watchersyncer.go 89: Start called
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-11-16 16:58:19.780 [INFO][63] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}} ifaceName="ens5.1000"
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-11-16 16:58:19.780 [INFO][63] daemon.go 454: Started the processing graph
2019-11-16 16:58:19.780 [INFO][63] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-11-16 16:58:19.781 [INFO][63] watchersyncer.go 147: Starting main event processing loop
2019-11-16 16:58:19.781 [INFO][63] daemon.go 813: Reading from dataplane driver pipe...
2019-11-16 16:58:19.780 [INFO][63] int_dataplane.go 983: Process status reports disabled
2019-11-16 16:58:19.781 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-11-16 16:58:19.781 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-11-16 16:58:19.781 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-11-16 16:58:19.781 [INFO][63] async_calc_graph.go 134: AsyncCalcGraph running
2019-11-16 16:58:19.781 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-11-16 16:58:19.781 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.782 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-11-16 16:58:19.782 [INFO][63] daemon.go 546: No driver process to monitor
2019-11-16 16:58:19.782 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.782 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fec7:2624":set.empty{}, "192.168.11.37":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fec7:2624":set.empty{}, "192.168.11.37":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fec7:2624":set.empty{}, "192.168.11.37":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.783 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-11-16 16:58:19.783 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.783 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-11-16 16:58:19.783 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.783 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.784 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-11-16 16:58:19.784 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 127: Sending status update Status=resync
2019-11-16 16:58:19.784 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe3d:c4b4":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-11-16 16:58:19.784 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:feb4:dadf":set.empty{}}}
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.784 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-11-16 16:58:19.784 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.785 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.784 [INFO][63] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"6e78891db03e4026a7766acf3b36b7b3" > config:<key:"ClusterType" value:"k8s,bgp" > config:<key:"DefaultEndpointToHostAction" value:"Return" > config:<key:"EtcdCaFile" value:"/var/lib/etcd/ca.pem" > config:<key:"EtcdCertFile" value:"/var/lib/etcd/etcd-client.crt" > config:<key:"EtcdEndpoints" value:"https://172.16.10.36:4001" > config:<key:"EtcdKeyFile" value:"/var/lib/etcd/etcd-client.key" > config:<key:"FelixHostname" value:"cmp002" > 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" > 
2019-11-16 16:58:19.785 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-11-16 16:58:19.785 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.785 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-11-16 16:58:19.785 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 6e78891db03e4026a7766acf3b36b7b3 6 0s} 1}
2019-11-16 16:58:19.785 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-11-16 16:58:19.786 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-11-16 16:58:19.786 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-11-16 16:58:19.786 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-11-16 16:58:19.786 [INFO][63] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp002,name=DefaultEndpointToHostAction) Return 8 0s} 1}
2019-11-16 16:58:19.786 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.786 [INFO][63] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-11-16 16:58:19.786 [INFO][63] watchersyncer.go 127: Sending status update Status=in-sync
2019-11-16 16:58:19.787 [INFO][63] config_batcher.go 102: Datamodel in sync, flushing config update
2019-11-16 16:58:19.787 [INFO][63] config_batcher.go 112: Sending config update global: map[CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:6e78891db03e4026a7766acf3b36b7b3 ClusterType:k8s,bgp], host: map[DefaultEndpointToHostAction:Return].
2019-11-16 16:58:19.787 [INFO][63] async_calc_graph.go 160: First time we've been in sync
2019-11-16 16:58:19.788 [INFO][63] event_sequencer.go 210: Possible config update. global=map[string]string{"LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-11-16 16:58:19.788 [INFO][63] config_params.go 217: Merging in config from datastore (global): map[LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:6e78891db03e4026a7766acf3b36b7b3 ClusterType:k8s,bgp CalicoVersion:v3.3.2]
2019-11-16 16:58:19.788 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.788 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:19.796 [INFO][63] usagerep.go 83: Waiting before first check-in delay=5m1.847s
2019-11-16 16:58:19.796 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.796 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:19.797 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.797 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:19.797 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.798 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.798 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:19.799 [INFO][63] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-11-16 16:58:19.799 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:19.800 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:19.800 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.800 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.801 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.801 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.802 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:19.802 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:19.802 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:19.802 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:19.802 [INFO][63] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-11-16 16:58:19.802 [INFO][63] daemon.go 892: Datastore now in sync.
2019-11-16 16:58:19.802 [INFO][63] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"192.168.0.0-16" pool:<cidr:"192.168.0.0/16" masquerade:true > 
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fd0b:52a8:5995::-48" pool:<cidr:"fd0b:52a8:5995::/48" > 
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=168.607441ms
2019-11-16 16:58:19.802 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:19.802 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.802 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.802 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.803 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.803 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.804 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-11-16 16:58:19.804 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.804 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:19.805 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:19.805 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:19.805 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:19.816 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=11.589767ms
2019-11-16 16:58:19.817 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=12.341723ms
2019-11-16 16:58:19.817 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-11-16 16:58:19.817 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:19.817 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-11-16 16:58:19.817 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:19.818 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-11-16 16:58:19.818 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-11-16 16:58:19.945 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:19.946 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:19.948 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:19.950 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:19.951 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.953 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:19.956 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.960 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:20.403 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=600.1951359999999
2019-11-16 16:58:20.403 [INFO][63] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.769005282
2019-11-16 16:58:21.477 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:21.477 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:21.478 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:21.479 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:21.481 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:21.482 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:21.483 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:21.486 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:21.487 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:21.489 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:21.491 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=14.21141
2019-11-16 16:58:22.033 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.033 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:22.034 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:22.035 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4305160000000003
2019-11-16 16:58:22.191 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.191 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:22.192 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:22.193 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.39539
2019-11-16 16:58:22.208 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:22.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:22.210 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:22.211 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:22.213 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.641529
2019-11-16 16:58:22.226 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.226 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:22.227 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:22.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.446204
2019-11-16 16:58:22.391 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.391 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:22.392 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:22.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.468419
2019-11-16 16:58:22.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:22.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:22.404 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.116367
2019-11-16 16:58:22.405 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.405 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:22.405 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:22.406 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.8037400000000001
2019-11-16 16:58:24.020 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.020 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:24.022 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:24.023 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.179548
2019-11-16 16:58:24.192 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.192 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:24.193 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:24.194 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.398532
2019-11-16 16:58:24.208 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:24.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:24.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:24.210 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:24.212 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.904747
2019-11-16 16:58:24.225 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.225 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:24.226 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:24.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.02256
2019-11-16 16:58:24.392 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.392 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:24.393 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:24.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.799521
2019-11-16 16:58:24.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:24.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:24.404 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.186524
2019-11-16 16:58:24.405 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.405 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:24.405 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:24.406 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.859629
2019-11-16 16:58:28.020 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.020 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:28.022 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:28.023 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6208080000000002
2019-11-16 16:58:28.191 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.191 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:28.192 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:28.194 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.462619
2019-11-16 16:58:28.208 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:28.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:28.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:28.211 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:28.213 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.8235470000000005
2019-11-16 16:58:28.226 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.226 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:28.227 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:28.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1630640000000003
2019-11-16 16:58:28.391 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.391 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:28.392 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:28.393 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.408968
2019-11-16 16:58:28.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:28.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:28.405 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.663451
2019-11-16 16:58:28.405 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.405 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:28.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:28.409 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.850264
2019-11-16 16:58:30.358 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:30.358 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:30.358 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:30.358 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:30.358 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:30.360 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.168835ms
2019-11-16 16:58:30.361 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.350626ms
2019-11-16 16:58:30.361 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.877119
2019-11-16 16:58:36.019 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.019 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:36.025 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:36.027 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.238778
2019-11-16 16:58:36.197 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.197 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:36.198 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:36.199 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.310187
2019-11-16 16:58:36.208 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:36.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:36.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:36.210 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:36.212 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.688835
2019-11-16 16:58:36.225 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.225 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:36.226 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:36.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.828921
2019-11-16 16:58:36.391 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.392 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:36.394 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:36.396 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.210546
2019-11-16 16:58:36.403 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.404 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:36.404 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:36.405 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:36.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:36.407 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2105390000000003
2019-11-16 16:58:40.910 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:40.910 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:40.910 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:40.910 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:40.911 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:40.913 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.810772ms
2019-11-16 16:58:40.914 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.964438ms
2019-11-16 16:58:40.914 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.810757
2019-11-16 16:58:50.976 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:50.976 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:50.976 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:50.976 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:50.976 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:50.980 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.807937ms
2019-11-16 16:58:50.980 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.726402ms
2019-11-16 16:58:50.980 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.090247
2019-11-16 16:58:52.019 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.019 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:52.024 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:52.026 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.233532
2019-11-16 16:58:52.196 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.196 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:52.197 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:52.200 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.019196
2019-11-16 16:58:52.210 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.210 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:52.210 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:52.211 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:52.212 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:52.214 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.195002
2019-11-16 16:58:52.225 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.225 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:52.227 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:52.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.069816
2019-11-16 16:58:52.392 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.392 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:52.393 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:52.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.776163
2019-11-16 16:58:52.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:52.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:52.405 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.314955
2019-11-16 16:58:52.406 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.406 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:52.407 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:52.408 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2841139999999998
2019-11-16 16:59:01.853 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:01.853 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:01.853 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:01.853 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:01.853 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:01.854 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.204771ms
2019-11-16 16:59:01.855 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.400291ms
2019-11-16 16:59:01.855 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.013998
2019-11-16 16:59:12.354 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:12.354 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:12.354 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:12.354 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:12.354 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:12.357 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.933281ms
2019-11-16 16:59:12.358 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.966537ms
2019-11-16 16:59:12.359 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.785122
2019-11-16 16:59:23.052 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:23.052 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:23.052 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:23.052 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:23.052 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:23.053 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.147543ms
2019-11-16 16:59:23.053 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.08187ms
2019-11-16 16:59:23.054 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.625891
2019-11-16 16:59:24.019 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.019 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:24.021 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:24.023 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c"} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", ""} ipVersion=0x4 table="filter"
2019-11-16 16:59:24.023 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-11-16 16:59:24.025 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.492627
2019-11-16 16:59:24.195 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.196 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:24.199 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:24.201 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-11-16 16:59:24.203 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.302593
2019-11-16 16:59:24.213 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.213 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:59:24.213 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:59:24.215 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:59:24.217 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:59:24.219 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.167947
2019-11-16 16:59:24.227 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.227 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:59:24.229 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:59:24.234 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.783116
2019-11-16 16:59:24.395 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.395 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:59:24.396 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:59:24.398 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.434753
2019-11-16 16:59:24.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:59:24.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:59:24.404 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6116
2019-11-16 16:59:24.405 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.405 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:59:24.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:59:24.407 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.890854
2019-11-16 16:59:25.027 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.027 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:25.029 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:25.032 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.498834
2019-11-16 16:59:25.207 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.207 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:25.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:25.211 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.148911
2019-11-16 16:59:26.029 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:26.030 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:26.031 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:26.032 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.915305
2019-11-16 16:59:26.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:26.206 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:26.207 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:26.208 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.664598
2019-11-16 16:59:28.028 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:28.028 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:28.029 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:28.031 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.085697
2019-11-16 16:59:28.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:28.206 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:28.207 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:28.209 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.045629
2019-11-16 16:59:32.028 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:32.029 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:32.030 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:32.032 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.209679
2019-11-16 16:59:32.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:32.206 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:32.208 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:32.209 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.327715
2019-11-16 16:59:33.717 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:33.717 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:33.717 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:33.718 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:33.718 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:33.719 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.567424ms
2019-11-16 16:59:33.719 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.383015ms
2019-11-16 16:59:33.720 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.147961
2019-11-16 16:59:40.025 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:40.025 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:40.026 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:40.028 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8869059999999998
2019-11-16 16:59:40.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:40.206 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:40.207 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:40.208 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.271244
2019-11-16 16:59:43.868 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:43.868 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:43.868 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:43.868 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:43.868 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:43.870 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.704074ms
2019-11-16 16:59:43.870 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.910818ms
2019-11-16 16:59:43.870 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.204691
2019-11-16 16:59:52.545 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:52.545 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 16:59:52.545 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 16:59:52.546 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.445555
2019-11-16 16:59:54.401 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:54.401 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:54.401 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:54.401 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:54.401 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:54.402 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.232333ms
2019-11-16 16:59:54.402 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.116062ms
2019-11-16 16:59:54.403 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.8231490000000001
2019-11-16 16:59:56.025 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:56.026 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:56.027 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:56.030 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.410102
2019-11-16 16:59:56.207 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:56.207 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:56.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:56.211 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.208831
2019-11-16 17:00:04.602 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:04.602 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:04.602 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:04.603 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:04.603 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:04.604 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.531245ms
2019-11-16 17:00:04.604 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.720591ms
2019-11-16 17:00:04.605 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.34318
2019-11-16 17:00:15.569 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:15.569 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:15.569 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:15.569 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:15.569 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:15.571 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.936688ms
2019-11-16 17:00:15.571 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.048523ms
2019-11-16 17:00:15.571 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.541318
2019-11-16 17:00:25.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:25.818 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:25.818 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:25.818 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:25.818 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:25.820 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.092784ms
2019-11-16 17:00:25.820 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.038795ms
2019-11-16 17:00:25.821 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.675973
2019-11-16 17:00:28.025 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.026 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:28.027 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:28.028 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c", ""} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", "", ""} ipVersion=0x4 table="filter"
2019-11-16 17:00:28.028 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-11-16 17:00:28.028 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-11-16 17:00:28.030 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.755299999999999
2019-11-16 17:00:28.207 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:00:28.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:28.208 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:00:28.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:00:28.210 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:28.212 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:00:28.213 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-11-16 17:00:28.213 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-11-16 17:00:28.215 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.089222
2019-11-16 17:00:28.228 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.228 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:28.229 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:28.231 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5170660000000002
2019-11-16 17:00:28.391 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.391 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:00:28.392 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:00:28.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.517134
2019-11-16 17:00:28.402 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.402 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:00:28.403 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:00:28.404 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4833580000000004
2019-11-16 17:00:28.405 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.405 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:00:28.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:00:28.407 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.024536
2019-11-16 17:00:29.032 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.033 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:29.034 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:29.042 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.353869000000001
2019-11-16 17:00:29.224 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.224 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:29.226 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:29.229 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.558306
2019-11-16 17:00:30.035 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.035 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:30.037 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:30.040 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.138879
2019-11-16 17:00:30.220 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.220 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:30.221 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:30.226 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.065683
2019-11-16 17:00:32.036 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:32.037 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:32.038 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:32.041 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.794466
2019-11-16 17:00:32.219 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:32.220 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:32.221 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:32.224 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.152258
2019-11-16 17:00:36.035 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.035 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:36.037 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:36.040 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.275404
2019-11-16 17:00:36.220 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.220 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:36.221 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:36.223 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.799143
2019-11-16 17:00:36.616 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.616 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:36.617 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:36.617 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:36.617 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:36.620 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.722014ms
2019-11-16 17:00:36.622 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.843054ms
2019-11-16 17:00:36.622 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.459818
2019-11-16 17:00:42.865 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.865 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{}}
2019-11-16 17:00:42.865 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{}}
2019-11-16 17:00:42.865 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{}}
2019-11-16 17:00:42.865 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.865 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.140461
2019-11-16 17:00:42.867 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="cali2d04ad34e65" state="up"
2019-11-16 17:00:42.868 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.868 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali2d04ad34e65", State:"up"}
2019-11-16 17:00:42.869 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.869 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.869 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.869 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.869 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.870 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.64/32 ifaceName="cali2d04ad34e65" ipVersion=0x4
2019-11-16 17:00:42.870 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali2d04ad34e65" ipVersion=0x4
2019-11-16 17:00:42.870 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.144579
2019-11-16 17:00:42.870 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.871 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.871 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d04ad34e65", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.871 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.872 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.64/32 ifaceName="cali2d04ad34e65" ipVersion=0x4
2019-11-16 17:00:42.872 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali2d04ad34e65" ipVersion=0x4
2019-11-16 17:00:42.872 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.8693350000000001
2019-11-16 17:00:42.877 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-w98nt, name=eth0)
2019-11-16 17:00:42.877 [INFO][63] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"allow" rule_id:"YLdFWiauLlZiqqnX" > outbound_rules:<action:"allow" rule_id:"s12JEevpe1A9nAkJ" > > 
2019-11-16 17:00:42.878 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.878 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:42.878 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.878 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.878 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:42.878 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.878 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-w98nt" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali2d04ad34e65" mac:"36:40:8e:0f:66:f9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-11-16 17:00:42.878 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.879 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d04ad34e65" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d04ad34e65" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.879 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.879 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.879 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.879 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.879 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d04ad34e65" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.879 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d04ad34e65" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.880 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.880 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.880 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.880 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:42.880 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.880 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:42.882 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:42.885 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:42.890 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-11-16 17:00:42.890 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"} status="up"
2019-11-16 17:00:42.890 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.639648000000001
2019-11-16 17:00:43.112 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali11c065c238a"
2019-11-16 17:00:43.113 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{}}
2019-11-16 17:00:43.113 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{}}
2019-11-16 17:00:43.113 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{}}
2019-11-16 17:00:43.113 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.113 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.15065599999999998
2019-11-16 17:00:43.115 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="cali11c065c238a" state="up"
2019-11-16 17:00:43.115 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali11c065c238a", State:"up"}
2019-11-16 17:00:43.115 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali11c065c238a"
2019-11-16 17:00:43.115 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.115 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.116 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.116 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.116 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.117 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="cali11c065c238a" ipVersion=0x4
2019-11-16 17:00:43.117 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali11c065c238a" ipVersion=0x4
2019-11-16 17:00:43.117 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.587818
2019-11-16 17:00:43.117 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.117 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.117 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali11c065c238a", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.117 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.118 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="cali11c065c238a" ipVersion=0x4
2019-11-16 17:00:43.118 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali11c065c238a" ipVersion=0x4
2019-11-16 17:00:43.118 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.637368
2019-11-16 17:00:43.125 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-v2ccc, name=eth0)
2019-11-16 17:00:43.125 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-v2ccc" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali11c065c238a" mac:"4a:37:ea:4e:d5:b3" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-11-16 17:00:43.125 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.125 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.125 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali11c065c238a" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.125 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:43.125 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali11c065c238a" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.125 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.125 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.125 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.126 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.126 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali11c065c238a" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.126 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:43.126 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali11c065c238a" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.126 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.126 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:43.126 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.126 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:43.128 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:43.130 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:43.134 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:43.134 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"} status="up"
2019-11-16 17:00:43.134 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.754423000000001
2019-11-16 17:00:44.056 [INFO][63] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-11-16 17:00:44.140 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:44.140 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:44.140 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:44.142 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:44.144 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:44.147 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.367774
2019-11-16 17:00:44.222 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:44.222 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:44.224 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:44.226 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.186207
2019-11-16 17:00:44.760 [INFO][63] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-11-16 17:00:45.137 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:45.137 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:45.137 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:45.138 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:45.140 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:45.145 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.628986
2019-11-16 17:00:46.860 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:46.860 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:46.860 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:46.860 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:46.861 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:46.862 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.139147ms
2019-11-16 17:00:46.862 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.146462ms
2019-11-16 17:00:46.862 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.746113
2019-11-16 17:00:47.133 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:47.133 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:47.134 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:47.136 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.482422
2019-11-16 17:00:47.137 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:47.137 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:47.138 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:47.140 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.474048
2019-11-16 17:00:48.552 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-w98nt, name=eth0)
2019-11-16 17:00:48.553 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-w98nt" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali2d04ad34e65" mac:"36:40:8e:0f:66:f9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-11-16 17:00:48.553 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.553 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.553 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d04ad34e65" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.553 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.553 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d04ad34e65" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.553 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.553 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:48.553 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.553 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.553 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.553 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d04ad34e65" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.553 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.553 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d04ad34e65" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.554 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.554 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d04ad34e65"
2019-11-16 17:00:48.554 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.554 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"}
2019-11-16 17:00:48.556 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.559 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.560 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:48.561 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-w98nt", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.561 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.762735
2019-11-16 17:00:48.759 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-v2ccc, name=eth0)
2019-11-16 17:00:48.760 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-v2ccc" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali11c065c238a" mac:"4a:37:ea:4e:d5:b3" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-11-16 17:00:48.760 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.760 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.760 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali11c065c238a" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.760 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.760 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali11c065c238a" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.760 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.760 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:48.762 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.762 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.762 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.763 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali11c065c238a" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.763 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.763 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali11c065c238a" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.763 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.763 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali11c065c238a"
2019-11-16 17:00:48.763 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.763 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"}
2019-11-16 17:00:48.764 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.767 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.769 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:48.769 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-v2ccc", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.769 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.455283
2019-11-16 17:00:51.139 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:51.139 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:51.139 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:51.140 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:51.141 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:51.144 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.190449
2019-11-16 17:00:57.606 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:57.606 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:57.606 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:57.606 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:57.606 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:57.608 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.156117ms
2019-11-16 17:00:57.609 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.049977ms
2019-11-16 17:00:57.610 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.713947
2019-11-16 17:00:59.133 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:59.133 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:59.136 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:59.139 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.111364999999999
2019-11-16 17:00:59.140 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:59.140 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:59.141 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:59.144 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.073348
2019-11-16 17:01:00.219 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:00.219 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:00.221 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:00.226 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.243358
2019-11-16 17:01:08.014 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:08.014 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:08.014 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:08.014 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:08.014 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:08.017 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.306224ms
2019-11-16 17:01:08.017 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.722535ms
2019-11-16 17:01:08.017 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1427199999999997
2019-11-16 17:01:15.133 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:15.133 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:15.136 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:15.138 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.190939999999999
2019-11-16 17:01:15.139 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:15.139 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:15.141 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:15.142 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2373329999999996
2019-11-16 17:01:18.426 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:18.427 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:18.427 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:18.427 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:18.427 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:18.428 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.385967ms
2019-11-16 17:01:18.428 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.295484ms
2019-11-16 17:01:18.428 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.648163
2019-11-16 17:01:28.509 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:28.509 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:28.509 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:28.509 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:28.510 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:28.513 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.89243ms
2019-11-16 17:01:28.515 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.785172ms
2019-11-16 17:01:28.515 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.952071
2019-11-16 17:01:29.836 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:29.836 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:01:29.836 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:01:29.838 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.993604
2019-11-16 17:01:32.216 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:32.216 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:32.218 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:32.228 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.468624
2019-11-16 17:01:39.036 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:39.036 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:39.036 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:39.036 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:39.036 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:39.039 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.663275ms
2019-11-16 17:01:39.039 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.079912ms
2019-11-16 17:01:39.039 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.675783
2019-11-16 17:01:47.133 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:47.133 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:47.134 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:47.136 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:47.138 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:47.144 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.052756
2019-11-16 17:01:49.439 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:49.440 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:49.440 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:49.440 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:49.440 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:49.443 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.798053ms
2019-11-16 17:01:49.444 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.927609ms
2019-11-16 17:01:49.444 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.258024
2019-11-16 17:01:58.209 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.209 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-11-16 17:01:58.212 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:01:58.215 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.86181
2019-11-16 17:01:58.218 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.219 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-11-16 17:01:58.228 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:01:58.229 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.961495999999999
2019-11-16 17:01:58.403 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.404 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-11-16 17:01:58.404 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-11-16 17:01:58.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:01:58.408 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:01:58.410 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.676608
2019-11-16 17:01:58.413 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.413 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-11-16 17:01:58.414 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:01:58.416 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8997260000000002
2019-11-16 17:01:59.612 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:59.612 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:59.612 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:59.612 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:59.612 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:59.617 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.556207ms
2019-11-16 17:01:59.617 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.712284ms
2019-11-16 17:01:59.617 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.5884730000000005
2019-11-16 17:02:10.455 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:10.455 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:10.455 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:10.455 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:10.455 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:10.457 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.416997ms
2019-11-16 17:02:10.458 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.383959ms
2019-11-16 17:02:10.458 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.718919
2019-11-16 17:02:20.909 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:20.909 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:20.909 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:20.909 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:20.909 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:20.910 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.16742ms
2019-11-16 17:02:20.910 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.284808ms
2019-11-16 17:02:20.910 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.5390270000000001
2019-11-16 17:02:31.531 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:31.532 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:31.532 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:31.532 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:31.532 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:31.533 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.365134ms
2019-11-16 17:02:31.534 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.660201ms
2019-11-16 17:02:31.534 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.221659
2019-11-16 17:02:36.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.206 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:02:36.207 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:02:36.209 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8453720000000002
2019-11-16 17:02:36.210 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.210 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:02:36.211 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:02:36.213 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.585746
2019-11-16 17:02:36.217 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.217 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:02:36.218 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:02:36.221 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.087756
2019-11-16 17:02:36.393 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.393 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:02:36.394 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:02:36.396 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.326632
2019-11-16 17:02:36.403 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.403 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:02:36.403 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:02:36.404 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:02:36.406 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:02:36.407 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.570816
2019-11-16 17:02:42.438 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:42.438 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:42.438 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:42.438 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:42.439 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:42.440 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.260755ms
2019-11-16 17:02:42.441 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.858285ms
2019-11-16 17:02:42.441 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.508617
2019-11-16 17:02:51.133 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:51.133 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:02:51.135 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:02:51.137 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.424028
2019-11-16 17:02:51.138 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:51.138 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:02:51.140 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:02:51.142 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9876850000000004
2019-11-16 17:02:53.351 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:53.351 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:53.351 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:53.352 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:53.352 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:53.354 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.438168ms
2019-11-16 17:02:53.355 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.606341ms
2019-11-16 17:02:53.355 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.93829
2019-11-16 17:03:02.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:02.950 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:03:02.950 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:03:02.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.0720769999999997
2019-11-16 17:03:03.852 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:03.852 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:03.852 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:03.852 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:03.852 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:03.858 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=5.272773ms
2019-11-16 17:03:03.858 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=5.396597ms
2019-11-16 17:03:03.858 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.848475
2019-11-16 17:03:14.264 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:14.264 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:14.264 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:14.264 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:14.264 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:14.265 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.511389ms
2019-11-16 17:03:14.266 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.973098ms
2019-11-16 17:03:14.266 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.463
2019-11-16 17:03:21.644 [INFO][63] usagerep.go 106: Initial delay complete, doing first report
2019-11-16 17:03:21.644 [INFO][63] usagerep.go 185: Reporting cluster usage/checking for deprecation warnings. alpEnabled=false calicoVersion="v3.3.2" clusterGUID="6e78891db03e4026a7766acf3b36b7b3" clusterType="k8s,bgp" gitRevision="1edd26adb1cfe5c6ff437467d429608428fbd1fe" stats=calc.StatsUpdate{NumHosts:3, NumWorkloadEndpoints:6, NumHostEndpoints:0, NumPolicies:0, NumProfiles:5, NumALPPolicies:0} version="v3.3.2"
2019-11-16 17:03:22.798 [INFO][63] usagerep.go 108: First report done, starting ticker
2019-11-16 17:03:25.036 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:25.037 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:25.037 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:25.037 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:25.037 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:25.039 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.275094ms
2019-11-16 17:03:25.040 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.629833ms
2019-11-16 17:03:25.041 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.954704
2019-11-16 17:03:35.378 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:35.378 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:35.378 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:35.378 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:35.378 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:35.381 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.152057ms
2019-11-16 17:03:35.381 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.746081ms
2019-11-16 17:03:35.381 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.31045
2019-11-16 17:03:46.132 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:46.132 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:46.132 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:46.132 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:46.133 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:46.134 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.958732ms
2019-11-16 17:03:46.135 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.165236ms
2019-11-16 17:03:46.135 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.194544
