2019-11-16 16:58:19.933 [INFO][62] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp001", 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{"etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"cmp001", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001"}, 0x3:map[string]string{"LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None"}, 0x1:map[string]string{"CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdEndpoints":"https://172.16.10.36:4001", "DefaultEndpointToHostAction":"Return", "ReportingIntervalSecs":"0", "FelixHostname":"cmp001", "LogSeverityFile":"None", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "EtcdCaFile":"/var/lib/etcd/ca.pem", "MetadataAddr":"None", "LogFilePath":"None", "LogSeveritySys":"None", "LogSeverityScreen":"Info"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-11-16 16:58:19.934 [INFO][62] driver.go 43: Using internal (linux) dataplane driver.
2019-11-16 16:58:19.934 [INFO][62] 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.934 [INFO][62] 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)(0xc4204e9130), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204e9360), 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)(0xc4206a3480), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-11-16 16:58:19.934 [INFO][62] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4204e9130), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204e9360), 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.934 [INFO][62] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-11-16 16:58:19.934 [INFO][62] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-11-16 16:58:19.934 [INFO][62] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-11-16 16:58:19.936 [INFO][62] 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.936 [INFO][62] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:19.936 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.936 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.937 [INFO][62] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:19.937 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.938 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:19.938 [INFO][62] int_dataplane.go 424: Registering to report health.
2019-11-16 16:58:19.938 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.938 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.938 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.939 [INFO][62] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.939 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.939 [INFO][62] daemon.go 299: Connect to the dataplane driver.
2019-11-16 16:58:19.940 [INFO][62] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-11-16 16:58:19.940 [INFO][62] int_dataplane.go 981: Started internal status report thread
2019-11-16 16:58:19.940 [INFO][62] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4203b0100), (*watchersyncer.watcherCache)(0xc4203b0200), (*watchersyncer.watcherCache)(0xc4203b0280), (*watchersyncer.watcherCache)(0xc4203b0300), (*watchersyncer.watcherCache)(0xc4203b0500), (*watchersyncer.watcherCache)(0xc4203b0580), (*watchersyncer.watcherCache)(0xc4203b0600), (*watchersyncer.watcherCache)(0xc4203b0680), (*watchersyncer.watcherCache)(0xc4203b0700), (*watchersyncer.watcherCache)(0xc4203b0780)}, results:(chan interface {})(0xc4200bb740), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42069e178), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-11-16 16:58:19.940 [INFO][62] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp001
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:19.940 [INFO][62] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.941 [INFO][62] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:19.941 [INFO][62] daemon.go 439: Starting the datastore Syncer
2019-11-16 16:58:19.941 [INFO][62] watchersyncer.go 89: Start called
2019-11-16 16:58:19.941 [INFO][62] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-11-16 16:58:19.941 [INFO][62] daemon.go 454: Started the processing graph
2019-11-16 16:58:19.941 [INFO][62] daemon.go 813: Reading from dataplane driver pipe...
2019-11-16 16:58:19.941 [INFO][62] iface_monitor.go 88: Interface monitoring thread started.
2019-11-16 16:58:19.941 [INFO][62] iface_monitor.go 95: Subscribed to netlink updates.
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-11-16 16:58:19.940 [INFO][62] int_dataplane.go 983: Process status reports disabled
2019-11-16 16:58:19.940 [INFO][62] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-11-16 16:58:19.942 [INFO][62] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-11-16 16:58:19.942 [INFO][62] 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.942 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-11-16 16:58:19.942 [INFO][62] watchersyncer.go 147: Starting main event processing loop
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:feda:c364":set.empty{}, "192.168.11.36":set.empty{}} ifaceName="ens3"
2019-11-16 16:58:19.942 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-11-16 16:58:19.942 [INFO][62] 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.942 [INFO][62] 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.943 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}} ifaceName="ens4"
2019-11-16 16:58:19.943 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-11-16 16:58:19.943 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"::1":set.empty{}, "127.0.0.1":set.empty{}}}
2019-11-16 16:58:19.943 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}} ifaceName="ens5"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:feda:c364":set.empty{}, "192.168.11.36":set.empty{}}}
2019-11-16 16:58:19.943 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:feda:c364":set.empty{}}}
2019-11-16 16:58:19.943 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-11-16 16:58:19.943 [INFO][62] async_calc_graph.go 134: AsyncCalcGraph running
2019-11-16 16:58:19.943 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:feda:c364":set.empty{}, "192.168.11.36":set.empty{}}}
2019-11-16 16:58:19.943 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-11-16 16:58:19.943 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}}}
2019-11-16 16:58:19.944 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}, "172.16.10.55":set.empty{}} ifaceName="br-mgmt"
2019-11-16 16:58:19.944 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-11-16 16:58:19.943 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}}}
2019-11-16 16:58:19.944 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}} ifaceName="ens5.1000"
2019-11-16 16:58:19.944 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.944 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}, "172.16.10.55":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}, "172.16.10.55":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe88:ddd4":set.empty{}, "172.16.10.55":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.945 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-11-16 16:58:19.945 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:c357":set.empty{}}}
2019-11-16 16:58:19.945 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:19.946 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-11-16 16:58:19.946 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-11-16 16:58:19.946 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-11-16 16:58:19.946 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-11-16 16:58:19.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-11-16 16:58:19.946 [INFO][62] 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:"cmp001" > 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.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-11-16 16:58:19.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-11-16 16:58:19.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-11-16 16:58:19.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-11-16 16:58:19.944 [INFO][62] daemon.go 546: No driver process to monitor
2019-11-16 16:58:19.946 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 127: Sending status update Status=resync
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-11-16 16:58:19.947 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 6e78891db03e4026a7766acf3b36b7b3 6 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp001,name=DefaultEndpointToHostAction) Return 10 0s} 1}
2019-11-16 16:58:19.947 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-11-16 16:58:19.948 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.948 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:19.948 [INFO][62] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-11-16 16:58:19.948 [INFO][62] watchersyncer.go 127: Sending status update Status=in-sync
2019-11-16 16:58:19.948 [INFO][62] config_batcher.go 102: Datamodel in sync, flushing config update
2019-11-16 16:58:19.948 [INFO][62] 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.949 [INFO][62] async_calc_graph.go 160: First time we've been in sync
2019-11-16 16:58:19.949 [INFO][62] event_sequencer.go 210: Possible config update. global=map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-11-16 16:58:19.949 [INFO][62] usagerep.go 83: Waiting before first check-in delay=5m2.476s
2019-11-16 16:58:19.949 [INFO][62] config_params.go 217: Merging in config from datastore (global): map[ClusterGUID:6e78891db03e4026a7766acf3b36b7b3 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0]
2019-11-16 16:58:19.949 [INFO][62] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-11-16 16:58:19.949 [INFO][62] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-11-16 16:58:19.949 [INFO][62] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.949 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:19.951 [INFO][62] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.951 [INFO][62] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.952 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:19.952 [INFO][62] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.952 [INFO][62] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:19.952 [INFO][62] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:19.952 [INFO][62] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.952 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:19.953 [INFO][62] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.953 [INFO][62] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:19.953 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.953 [INFO][62] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:19.953 [INFO][62] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.954 [INFO][62] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.954 [INFO][62] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.954 [INFO][62] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:19.954 [INFO][62] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.955 [INFO][62] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-11-16 16:58:19.956 [INFO][62] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:19.956 [INFO][62] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:19.956 [INFO][62] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.956 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:19.956 [INFO][62] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.957 [INFO][62] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.957 [INFO][62] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:19.957 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.957 [INFO][62] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:19.958 [INFO][62] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:19.958 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:19.958 [INFO][62] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:19.958 [INFO][62] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:19.958 [INFO][62] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:19.958 [INFO][62] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.958 [INFO][62] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:19.959 [INFO][62] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:19.960 [INFO][62] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.960 [INFO][62] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:19.960 [INFO][62] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-11-16 16:58:19.960 [INFO][62] daemon.go 892: Datastore now in sync.
2019-11-16 16:58:19.960 [INFO][62] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-11-16 16:58:19.960 [INFO][62] 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.960 [INFO][62] 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.960 [INFO][62] 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.960 [INFO][62] 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.961 [INFO][62] 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.961 [INFO][62] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-11-16 16:58:19.961 [INFO][62] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=161.072321ms
2019-11-16 16:58:19.961 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:19.963 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.963 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.964 [INFO][62] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.964 [INFO][62] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-11-16 16:58:19.964 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-11-16 16:58:19.964 [INFO][62] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:19.964 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:19.964 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:19.964 [INFO][62] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:19.978 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=13.584444ms
2019-11-16 16:58:19.978 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:19.978 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-11-16 16:58:19.979 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-11-16 16:58:19.979 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=14.424444ms
2019-11-16 16:58:19.979 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-11-16 16:58:19.979 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-11-16 16:58:19.979 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:20.118 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:20.120 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:20.122 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:20.124 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:20.126 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:20.128 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:20.129 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:20.130 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:20.677 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=715.606618
2019-11-16 16:58:20.677 [INFO][62] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.877516019
2019-11-16 16:58:21.774 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:21.774 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:21.775 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:21.776 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:21.777 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:21.780 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:21.781 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:21.782 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:21.784 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:21.785 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:21.787 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:21.791 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.260682
2019-11-16 16:58:22.231 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.231 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:22.232 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:22.234 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.781428
2019-11-16 16:58:22.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:22.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:22.439 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.547546
2019-11-16 16:58:22.456 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:22.457 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:22.458 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.924614
2019-11-16 16:58:22.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.460 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:22.463 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:22.465 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.221849
2019-11-16 16:58:22.474 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.474 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:22.474 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:22.474 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:22.476 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:22.477 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.578949
2019-11-16 16:58:22.633 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.633 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:22.634 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:22.635 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.264137
2019-11-16 16:58:22.679 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.679 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:22.681 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:22.682 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2866269999999997
2019-11-16 16:58:24.218 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.218 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:24.219 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:24.221 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.779436
2019-11-16 16:58:24.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:24.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:24.438 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.452017
2019-11-16 16:58:24.455 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:24.456 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:24.457 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.937224
2019-11-16 16:58:24.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.461 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:24.461 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:24.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8391409999999997
2019-11-16 16:58:24.472 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.474 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:24.474 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:24.475 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:24.476 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:24.477 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.695338
2019-11-16 16:58:24.633 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.633 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:24.635 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:24.637 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.233894
2019-11-16 16:58:24.681 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.682 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:24.684 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:24.686 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.051869
2019-11-16 16:58:28.220 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.220 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:28.221 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:28.223 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1902380000000004
2019-11-16 16:58:28.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:28.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:28.439 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.324177
2019-11-16 16:58:28.455 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.455 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:28.456 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:28.457 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1275999999999997
2019-11-16 16:58:28.461 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.461 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:28.462 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:28.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1576299999999997
2019-11-16 16:58:28.471 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.472 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:28.472 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:28.473 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.943896
2019-11-16 16:58:28.475 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.475 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:28.476 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:28.477 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.61669
2019-11-16 16:58:28.632 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.632 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:28.635 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:28.636 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.221326
2019-11-16 16:58:28.681 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.681 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:28.682 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:28.684 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.540419
2019-11-16 16:58:30.541 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:30.541 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:30.541 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:30.541 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:30.541 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:30.543 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.448858ms
2019-11-16 16:58:30.543 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.6227ms
2019-11-16 16:58:30.544 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.758571
2019-11-16 16:58:36.215 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.215 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:36.216 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:36.218 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8270679999999997
2019-11-16 16:58:36.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:36.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:36.439 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7991919999999997
2019-11-16 16:58:36.456 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:36.457 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:36.458 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9736200000000002
2019-11-16 16:58:36.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.461 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:36.462 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:36.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.480665
2019-11-16 16:58:36.472 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.472 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:36.473 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:36.474 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3165780000000002
2019-11-16 16:58:36.475 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.475 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:36.476 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:36.478 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.120086
2019-11-16 16:58:36.632 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.633 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:36.634 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:36.635 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7497599999999998
2019-11-16 16:58:36.680 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.680 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:36.681 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:36.683 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.942115
2019-11-16 16:58:40.812 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:40.812 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:40.812 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:40.812 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:40.812 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:40.815 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.470358ms
2019-11-16 16:58:40.815 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.905648ms
2019-11-16 16:58:40.815 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.467836
2019-11-16 16:58:51.751 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:51.751 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:51.751 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:51.751 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:51.751 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:51.752 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=920.035µs
2019-11-16 16:58:51.752 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.09442ms
2019-11-16 16:58:51.752 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.29491
2019-11-16 16:58:52.215 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.215 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:52.216 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:52.218 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.655569
2019-11-16 16:58:52.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:52.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:52.438 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.552365
2019-11-16 16:58:52.456 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:52.457 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:52.458 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.769321
2019-11-16 16:58:52.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.460 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:52.461 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:52.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.362529
2019-11-16 16:58:52.472 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.472 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:52.473 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:52.474 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.112325
2019-11-16 16:58:52.475 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.475 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:52.477 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:52.478 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.881732
2019-11-16 16:58:52.632 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.632 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:52.633 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:52.635 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8329969999999998
2019-11-16 16:58:52.680 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.680 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:52.681 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:52.683 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9820189999999998
2019-11-16 16:59:02.445 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:02.445 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:02.445 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:02.445 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:02.445 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:02.447 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.044001ms
2019-11-16 16:59:02.447 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=870.026µs
2019-11-16 16:59:02.447 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.520003
2019-11-16 16:59:13.216 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:13.216 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:13.216 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:13.216 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:13.216 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:13.218 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.246561ms
2019-11-16 16:59:13.219 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.590511ms
2019-11-16 16:59:13.219 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.419406
2019-11-16 16:59:23.486 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:23.486 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:23.486 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:23.486 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:23.486 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:23.488 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.252689ms
2019-11-16 16:59:23.489 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.022488ms
2019-11-16 16:59:23.490 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.63116
2019-11-16 16:59:24.215 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.215 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:59:24.217 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:59:24.219 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.035965
2019-11-16 16:59:24.437 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.437 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:59:24.438 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:59:24.440 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.426297
2019-11-16 16:59:24.456 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:59:24.457 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:59:24.458 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.83012
2019-11-16 16:59:24.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.460 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:59:24.461 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:59:24.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2673889999999997
2019-11-16 16:59:24.472 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.472 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:24.473 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:24.475 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.085466
2019-11-16 16:59:24.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:59:24.477 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:59:24.479 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.617895
2019-11-16 16:59:24.632 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.632 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:59:24.633 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:59:24.635 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.664909
2019-11-16 16:59:24.680 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.680 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:24.681 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:24.682 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.236331
2019-11-16 16:59:33.550 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:33.550 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:33.550 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:33.550 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:33.550 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:33.553 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.199416ms
2019-11-16 16:59:33.553 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.675369ms
2019-11-16 16:59:33.553 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.17209
2019-11-16 16:59:43.960 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:43.960 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:43.960 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:43.960 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:43.960 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:43.961 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.059256ms
2019-11-16 16:59:43.961 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.264145ms
2019-11-16 16:59:43.961 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.519477
2019-11-16 16:59:49.957 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:49.958 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 16:59:49.958 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 16:59:49.958 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.672278
2019-11-16 16:59:54.558 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:54.558 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:54.558 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:54.558 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:54.558 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:54.559 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.046369ms
2019-11-16 16:59:54.559 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.216052ms
2019-11-16 16:59:54.559 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.4479339999999998
2019-11-16 17:00:04.594 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:04.594 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:04.594 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:04.594 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:04.595 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:04.596 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.238822ms
2019-11-16 17:00:04.596 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.620122ms
2019-11-16 17:00:04.596 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.212171
2019-11-16 17:00:14.865 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:14.865 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:14.865 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:14.865 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:14.866 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:14.866 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=941.346µs
2019-11-16 17:00:14.867 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.407446ms
2019-11-16 17:00:14.867 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.655303
2019-11-16 17:00:25.812 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:25.812 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:25.812 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:25.812 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:25.812 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:25.814 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.886955ms
2019-11-16 17:00:25.814 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.858216ms
2019-11-16 17:00:25.814 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.648186
2019-11-16 17:00:28.215 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.215 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:00:28.216 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:00:28.217 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6231850000000003
2019-11-16 17:00:28.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.436 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:00:28.437 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:00:28.438 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.545775
2019-11-16 17:00:28.456 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.456 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:00:28.456 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:00:28.457 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.703064
2019-11-16 17:00:28.460 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.460 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:00:28.461 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:00:28.462 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.996898
2019-11-16 17:00:28.471 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.471 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:28.472 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:28.474 [WARNING][62] 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.474 [WARNING][62] 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.474 [WARNING][62] 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 17:00:28.475 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.91193
2019-11-16 17:00:28.477 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.477 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:28.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:28.479 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.220908
2019-11-16 17:00:28.631 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.632 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:00:28.632 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:00:28.633 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.938288
2019-11-16 17:00:28.679 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.679 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:28.680 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:28.682 [WARNING][62] 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.682 [WARNING][62] 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.682 [WARNING][62] 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.683 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8465499999999997
2019-11-16 17:00:29.479 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.479 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:29.481 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:29.486 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.279415
2019-11-16 17:00:29.689 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.689 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:29.691 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:29.692 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.492542
2019-11-16 17:00:30.479 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.479 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:30.480 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:30.483 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7447280000000003
2019-11-16 17:00:30.686 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.687 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:30.688 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:30.691 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.235506
2019-11-16 17:00:32.480 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:32.480 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:32.481 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:32.483 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.153006
2019-11-16 17:00:32.686 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:32.686 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:32.688 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:32.691 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.510624
2019-11-16 17:00:36.153 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.153 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:36.153 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:36.153 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:36.153 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:36.154 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.258818ms
2019-11-16 17:00:36.155 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.337805ms
2019-11-16 17:00:36.155 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.899023
2019-11-16 17:00:36.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:36.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:36.480 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.497858000000001
2019-11-16 17:00:36.687 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.688 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:36.689 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:36.692 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.93424
2019-11-16 17:00:42.917 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali872d39137cf"
2019-11-16 17:00:42.918 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{}}
2019-11-16 17:00:42.918 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{}}
2019-11-16 17:00:42.918 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{}}
2019-11-16 17:00:42.918 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.918 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.192194
2019-11-16 17:00:42.921 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="cali872d39137cf" state="up"
2019-11-16 17:00:42.921 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali872d39137cf", State:"up"}
2019-11-16 17:00:42.921 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.921 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali872d39137cf"
2019-11-16 17:00:42.921 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.922 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.922 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.922 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.923 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.896102
2019-11-16 17:00:42.923 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.923 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.923 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali872d39137cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:42.924 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.924 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.37410699999999997
2019-11-16 17:00:42.930 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-vs5pv, name=eth0)
2019-11-16 17:00:42.930 [INFO][62] 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.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.931 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-vs5pv" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali872d39137cf" mac:"06:29:11:ad:89:21" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-11-16 17:00:42.931 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.931 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali872d39137cf" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali872d39137cf" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.931 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.931 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:42.932 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.932 [INFO][62] 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-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.932 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.932 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.932 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali872d39137cf" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.932 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali872d39137cf" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.932 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.932 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.932 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:42.932 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:42.932 [INFO][62] 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-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.932 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:42.933 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:42.937 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:42.944 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:42.944 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"} status="up"
2019-11-16 17:00:42.944 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=12.753707
2019-11-16 17:00:43.157 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calif79d416650b"
2019-11-16 17:00:43.157 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="calif79d416650b" state="up"
2019-11-16 17:00:43.158 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{}}
2019-11-16 17:00:43.158 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{}}
2019-11-16 17:00:43.158 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{}}
2019-11-16 17:00:43.158 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.158 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.113162
2019-11-16 17:00:43.158 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calif79d416650b", State:"up"}
2019-11-16 17:00:43.158 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.158 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calif79d416650b"
2019-11-16 17:00:43.158 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:43.158 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calif79d416650b"
2019-11-16 17:00:43.158 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:43.161 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calif79d416650b"
2019-11-16 17:00:43.162 [INFO][62] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.193/32 ifaceName="calif79d416650b" ipVersion=0x4
2019-11-16 17:00:43.162 [INFO][62] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calif79d416650b" ipVersion=0x4
2019-11-16 17:00:43.162 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.874956
2019-11-16 17:00:43.162 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.162 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.162 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calif79d416650b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.162 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.163 [INFO][62] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.193/32 ifaceName="calif79d416650b" ipVersion=0x4
2019-11-16 17:00:43.163 [INFO][62] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calif79d416650b" ipVersion=0x4
2019-11-16 17:00:43.163 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.655366
2019-11-16 17:00:43.169 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-x7l26, name=eth0)
2019-11-16 17:00:43.169 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-x7l26" endpoint_id:"eth0" > endpoint:<state:"active" name:"calif79d416650b" mac:"7a:46:b3:ba:20:17" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.193/32" > 
2019-11-16 17:00:43.169 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.169 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.169 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-calif79d416650b" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.169 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:43.169 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-calif79d416650b" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.169 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.169 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.170 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.170 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:43.170 [INFO][62] 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-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.170 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.170 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.170 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-calif79d416650b" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.170 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:43.170 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-calif79d416650b" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.170 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.170 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.170 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.170 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:43.170 [INFO][62] 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-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.170 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:43.171 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:43.180 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:43.186 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:43.186 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"} status="up"
2019-11-16 17:00:43.186 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.628967000000003
2019-11-16 17:00:43.417 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.417 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{}}
2019-11-16 17:00:43.417 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{}}
2019-11-16 17:00:43.418 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{}}
2019-11-16 17:00:43.418 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.418 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.116409
2019-11-16 17:00:43.420 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="cali6bdbdd14fcd" state="up"
2019-11-16 17:00:43.420 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali6bdbdd14fcd", State:"up"}
2019-11-16 17:00:43.420 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.420 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.420 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.420 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.421 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.421 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.422 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.600067
2019-11-16 17:00:43.422 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.422 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.422 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6bdbdd14fcd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:43.422 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.422 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.169038
2019-11-16 17:00:43.431 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-l6hmd, name=eth0)
2019-11-16 17:00:43.431 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-l6hmd" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali6bdbdd14fcd" mac:"b2:13:be:94:19:51" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.194/32" > 
2019-11-16 17:00:43.431 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.431 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali6bdbdd14fcd" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.431 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali6bdbdd14fcd" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.431 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:43.431 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.431 [INFO][62] 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-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.431 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.431 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali6bdbdd14fcd" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.431 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:43.431 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali6bdbdd14fcd" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.432 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.432 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.432 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:43.432 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:43.432 [INFO][62] 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-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.432 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:43.433 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:43.435 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:43.441 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:43.441 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"} status="up"
2019-11-16 17:00:43.441 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.518835000000001
2019-11-16 17:00:43.961 [INFO][62] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-11-16 17:00:44.447 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:44.447 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:44.447 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:44.449 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:44.450 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:44.452 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.3485700000000005
2019-11-16 17:00:44.480 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:44.480 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:44.481 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:44.482 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.744718
2019-11-16 17:00:44.794 [INFO][62] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-11-16 17:00:45.401 [INFO][62] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=10
2019-11-16 17:00:45.441 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:45.441 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:45.443 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:45.446 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.008294
2019-11-16 17:00:45.446 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:45.446 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:45.448 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:45.451 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.251945
2019-11-16 17:00:46.949 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:46.949 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:46.949 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:46.949 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:46.949 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:46.950 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.111039ms
2019-11-16 17:00:46.951 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.545618ms
2019-11-16 17:00:46.951 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.872214
2019-11-16 17:00:47.438 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:47.439 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:47.440 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:47.443 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.280257
2019-11-16 17:00:47.446 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:47.446 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:47.447 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:47.449 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.385245
2019-11-16 17:00:48.345 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-vs5pv, name=eth0)
2019-11-16 17:00:48.345 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-vs5pv" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali872d39137cf" mac:"06:29:11:ad:89:21" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-11-16 17:00:48.345 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.345 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.346 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali872d39137cf" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.346 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.346 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali872d39137cf" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.346 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.346 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:48.346 [INFO][62] 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-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.346 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.346 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.346 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali872d39137cf" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.346 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.346 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali872d39137cf" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.347 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.347 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali872d39137cf"
2019-11-16 17:00:48.347 [INFO][62] 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-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.347 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"}
2019-11-16 17:00:48.349 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.352 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.358 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:48.361 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-vs5pv", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.361 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=15.530353999999999
2019-11-16 17:00:48.545 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-l6hmd, name=eth0)
2019-11-16 17:00:48.545 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-l6hmd" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali6bdbdd14fcd" mac:"b2:13:be:94:19:51" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.194/32" > 
2019-11-16 17:00:48.546 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.546 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.546 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali6bdbdd14fcd" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.546 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.546 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali6bdbdd14fcd" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.546 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.546 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:48.546 [INFO][62] 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-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.546 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.546 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.546 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali6bdbdd14fcd" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.546 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.546 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali6bdbdd14fcd" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.546 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.547 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6bdbdd14fcd"
2019-11-16 17:00:48.547 [INFO][62] 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-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.547 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"}
2019-11-16 17:00:48.551 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.553 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.557 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-11-16 17:00:48.557 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-l6hmd", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.557 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.826168999999998
2019-11-16 17:00:48.757 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-x7l26, name=eth0)
2019-11-16 17:00:48.757 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-x7l26" endpoint_id:"eth0" > endpoint:<state:"active" name:"calif79d416650b" mac:"7a:46:b3:ba:20:17" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.193/32" > 
2019-11-16 17:00:48.757 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.757 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.757 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-calif79d416650b" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.757 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.757 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-calif79d416650b" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.757 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.757 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:48.757 [INFO][62] 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-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.758 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.758 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.758 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-calif79d416650b" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.758 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.758 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-calif79d416650b" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.758 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.758 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calif79d416650b"
2019-11-16 17:00:48.758 [INFO][62] 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-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.758 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"}
2019-11-16 17:00:48.759 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.761 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.763 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:48.763 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-x7l26", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.763 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.427638
2019-11-16 17:00:51.444 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:51.444 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:51.444 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:51.445 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:51.446 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:51.451 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.699809
2019-11-16 17:00:57.585 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:57.585 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:57.585 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:57.585 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:57.585 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:57.587 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.165841ms
2019-11-16 17:00:57.588 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.48873ms
2019-11-16 17:00:57.588 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.102201
2019-11-16 17:00:59.439 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:59.439 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:59.441 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:59.446 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.374943999999999
2019-11-16 17:00:59.448 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:59.449 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:59.450 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:59.453 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.439526
2019-11-16 17:01:00.480 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:00.480 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:00.482 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:00.485 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.506462
2019-11-16 17:01:08.496 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:08.496 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:08.496 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:08.496 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:08.496 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:08.498 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.187078ms
2019-11-16 17:01:08.498 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.97972ms
2019-11-16 17:01:08.499 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6136530000000002
2019-11-16 17:01:15.439 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:15.439 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:15.442 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:15.447 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.385864999999999
2019-11-16 17:01:15.450 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:15.450 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:15.451 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:15.454 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.855654
2019-11-16 17:01:19.345 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:19.345 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:19.345 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:19.345 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:19.346 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:19.348 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.235837ms
2019-11-16 17:01:19.348 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.489437ms
2019-11-16 17:01:19.349 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.335846
2019-11-16 17:01:25.184 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:25.185 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:01:25.185 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:01:25.196 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.716794
2019-11-16 17:01:30.068 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:30.068 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:30.068 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:30.068 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:30.069 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:30.071 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.179244ms
2019-11-16 17:01:30.071 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.617808ms
2019-11-16 17:01:30.071 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.948194
2019-11-16 17:01:32.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:32.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:32.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:32.483 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.965319999999999
2019-11-16 17:01:40.895 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:40.895 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:40.895 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:40.895 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:40.895 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:40.898 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.759885ms
2019-11-16 17:01:40.898 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.958935ms
2019-11-16 17:01:40.898 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6240040000000002
2019-11-16 17:01:47.439 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:47.439 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:47.441 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:47.445 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.3414589999999995
2019-11-16 17:01:47.448 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:47.448 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:47.450 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:47.454 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.076888
2019-11-16 17:01:51.770 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:51.770 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:51.770 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:51.771 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:51.771 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:51.773 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.387687ms
2019-11-16 17:01:51.773 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.121742ms
2019-11-16 17:01:51.773 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.120391
2019-11-16 17:01:58.216 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.217 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-11-16 17:01:58.219 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:01:58.222 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.046661
2019-11-16 17:01:58.443 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.443 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-11-16 17:01:58.445 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:01:58.449 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.352969
2019-11-16 17:01:58.463 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.463 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-11-16 17:01:58.463 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-11-16 17:01:58.464 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:01:58.466 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:01:58.467 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.163836
2019-11-16 17:01:58.637 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.637 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-11-16 17:01:58.638 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:01:58.641 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.323135
2019-11-16 17:02:02.209 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:02.209 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:02.209 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:02.209 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:02.209 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:02.213 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.730355ms
2019-11-16 17:02:02.213 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.012855ms
2019-11-16 17:02:02.214 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.4731119999999995
2019-11-16 17:02:12.504 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:12.504 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:12.504 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:12.504 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:12.504 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:12.507 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.362755ms
2019-11-16 17:02:12.507 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.854829ms
2019-11-16 17:02:12.508 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6256209999999998
2019-11-16 17:02:22.539 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:22.540 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:22.540 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:22.540 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:22.540 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:22.541 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.430562ms
2019-11-16 17:02:22.541 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.487184ms
2019-11-16 17:02:22.541 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9817379999999998
2019-11-16 17:02:32.703 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:32.703 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:32.704 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:32.704 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:32.704 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:32.705 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.849882ms
2019-11-16 17:02:32.705 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.725106ms
2019-11-16 17:02:32.706 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.135324
2019-11-16 17:02:36.215 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.215 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:02:36.216 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:02:36.218 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.754689
2019-11-16 17:02:36.436 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.437 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:02:36.439 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:02:36.441 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.361692000000001
2019-11-16 17:02:36.457 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.457 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:02:36.458 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:02:36.459 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.220638
2019-11-16 17:02:36.461 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.461 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:02:36.462 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:02:36.465 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.742129
2019-11-16 17:02:36.479 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.479 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:02:36.480 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:02:36.482 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.311319
2019-11-16 17:02:36.633 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.633 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:02:36.635 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:02:36.638 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.048629
2019-11-16 17:02:43.648 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:43.648 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:43.648 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:43.648 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:43.648 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:43.649 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.17869ms
2019-11-16 17:02:43.650 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.362878ms
2019-11-16 17:02:43.650 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.705624
2019-11-16 17:02:51.438 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:51.439 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:02:51.443 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:02:51.445 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.913167
2019-11-16 17:02:51.448 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:51.448 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:02:51.449 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:02:51.451 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0743099999999997
2019-11-16 17:02:54.174 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:54.174 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:54.174 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:54.174 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:54.175 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:54.176 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.314372ms
2019-11-16 17:02:54.176 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.73152ms
2019-11-16 17:02:54.177 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7981830000000003
2019-11-16 17:02:55.396 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:55.396 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:02:55.396 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:02:55.402 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.019718
2019-11-16 17:03:04.241 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:04.242 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:04.242 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:04.242 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:04.242 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:04.245 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.940036ms
2019-11-16 17:03:04.245 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.027961ms
2019-11-16 17:03:04.245 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.473373
2019-11-16 17:03:14.323 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:14.323 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:14.323 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:14.323 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:14.323 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:14.324 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.241464ms
2019-11-16 17:03:14.325 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.509048ms
2019-11-16 17:03:14.325 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9025999999999998
2019-11-16 17:03:22.425 [INFO][62] usagerep.go 106: Initial delay complete, doing first report
2019-11-16 17:03:22.425 [INFO][62] 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:23.533 [INFO][62] usagerep.go 108: First report done, starting ticker
2019-11-16 17:03:24.693 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:24.693 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:24.693 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:24.693 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:24.693 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:24.695 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.070309ms
2019-11-16 17:03:24.696 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.243778ms
2019-11-16 17:03:24.696 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.918121
2019-11-16 17:03:35.578 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:35.578 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:35.578 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:35.578 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:35.578 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:35.580 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.155259ms
2019-11-16 17:03:35.580 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.222982ms
2019-11-16 17:03:35.581 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.705946
2019-11-16 17:03:45.733 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:45.733 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:45.733 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:45.733 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:45.733 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:45.736 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.429638ms
2019-11-16 17:03:45.736 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.820678ms
2019-11-16 17:03:45.736 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.357026
