2019-08-28 16:14:38.126 [INFO][63] 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:"236357e2b4f74b22a557c3c0ddeb3a84", 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{0x3:map[string]string{"LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None"}, 0x1:map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"236357e2b4f74b22a557c3c0ddeb3a84", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}, 0x4:map[string]string{"felixhostname":"cmp001", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem"}}, rawValues:map[string]string{"LogSeverityFile":"None", "ReportingIntervalSecs":"0", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdEndpoints":"https://172.16.10.36:4001", "CalicoVersion":"v3.3.2", "EtcdCaFile":"/var/lib/etcd/ca.pem", "LogSeveritySys":"None", "DefaultEndpointToHostAction":"Return", "ClusterGUID":"236357e2b4f74b22a557c3c0ddeb3a84", "LogSeverityScreen":"Info", "FelixHostname":"cmp001", "LogFilePath":"None", "ClusterType":"k8s,bgp", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "MetadataAddr":"None"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-08-28 16:14:38.127 [INFO][63] driver.go 43: Using internal (linux) dataplane driver.
2019-08-28 16:14:38.127 [INFO][63] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-08-28 16:14:38.127 [INFO][63] int_dataplane.go 212: Creating internal dataplane driver. config=intdataplane.Config{IPv6Enabled:true, RuleRendererOverride:rules.RuleRenderer(nil), IPIPMTU:1440, IgnoreLooseRPF:false, MaxIPSetSize:1048576, IPSetsRefreshInterval:10000000000, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckInterval:1000000000, IptablesInsertMode:"insert", IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeout:0, IptablesLockProbeInterval:50000000, NetlinkTimeout:10000000000, RulesConfig:rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4204e4500), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204e45f0), 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)(0xc420414fe0), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-08-28 16:14:38.127 [INFO][63] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4204e4500), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204e45f0), 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-08-28 16:14:38.128 [INFO][63] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-08-28 16:14:38.128 [INFO][63] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-08-28 16:14:38.128 [INFO][63] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-08-28 16:14:38.129 [INFO][63] feature_detect.go 108: Updating detected iptables features features=iptables.Features{SNATFullyRandom:true, MASQFullyRandom:true, RestoreSupportsLock:true} iptablesVersion=1.6.2 kernelVersion=4.15.0
2019-08-28 16:14:38.130 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-08-28 16:14:38.130 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-08-28 16:14:38.130 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-08-28 16:14:38.131 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-08-28 16:14:38.132 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-08-28 16:14:38.132 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-08-28 16:14:38.132 [INFO][63] int_dataplane.go 424: Registering to report health.
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.132 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.133 [INFO][63] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.133 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-08-28 16:14:38.134 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-08-28 16:14:38.134 [INFO][63] daemon.go 299: Connect to the dataplane driver.
2019-08-28 16:14:38.134 [INFO][63] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc420152980), (*watchersyncer.watcherCache)(0xc420152a00), (*watchersyncer.watcherCache)(0xc420152a80), (*watchersyncer.watcherCache)(0xc420152b00), (*watchersyncer.watcherCache)(0xc420152b80), (*watchersyncer.watcherCache)(0xc420152c00), (*watchersyncer.watcherCache)(0xc420152c80), (*watchersyncer.watcherCache)(0xc420152d00), (*watchersyncer.watcherCache)(0xc420152d80), (*watchersyncer.watcherCache)(0xc420152e00)}, results:(chan interface {})(0xc4204e89c0), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc4204ec198), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-08-28 16:14:38.134 [INFO][63] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp001
2019-08-28 16:14:38.134 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-08-28 16:14:38.134 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-08-28 16:14:38.134 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-08-28 16:14:38.134 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-08-28 16:14:38.134 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:38.135 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:38.136 [INFO][63] daemon.go 439: Starting the datastore Syncer
2019-08-28 16:14:38.136 [INFO][63] watchersyncer.go 89: Start called
2019-08-28 16:14:38.136 [INFO][63] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-08-28 16:14:38.136 [INFO][63] daemon.go 454: Started the processing graph
2019-08-28 16:14:38.136 [INFO][63] daemon.go 813: Reading from dataplane driver pipe...
2019-08-28 16:14:38.136 [INFO][63] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-08-28 16:14:38.136 [INFO][63] watchersyncer.go 147: Starting main event processing loop
2019-08-28 16:14:38.136 [INFO][63] async_calc_graph.go 134: AsyncCalcGraph running
2019-08-28 16:14:38.136 [INFO][63] int_dataplane.go 981: Started internal status report thread
2019-08-28 16:14:38.136 [INFO][63] int_dataplane.go 983: Process status reports disabled
2019-08-28 16:14:38.136 [INFO][63] iface_monitor.go 88: Interface monitoring thread started.
2019-08-28 16:14:38.136 [INFO][63] iface_monitor.go 95: Subscribed to netlink updates.
2019-08-28 16:14:38.136 [INFO][63] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-08-28 16:14:38.137 [INFO][63] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-08-28 16:14:38.137 [INFO][63] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-08-28 16:14:38.137 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-08-28 16:14:38.137 [INFO][63] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"236357e2b4f74b22a557c3c0ddeb3a84" > 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-08-28 16:14:38.138 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe21:d2c8":set.empty{}} ifaceName="ens3"
2019-08-28 16:14:38.138 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-08-28 16:14:38.138 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.138 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe2b:a552":set.empty{}} ifaceName="ens4"
2019-08-28 16:14:38.138 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-08-28 16:14:38.138 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe21:d2c8":set.empty{}, "192.168.11.36":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe21:d2c8":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}} ifaceName="ens5"
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe21:d2c8":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe2b:a552":set.empty{}} ifaceName="br-mgmt"
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-08-28 16:14:38.139 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.139 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}} ifaceName="ens5.1000"
2019-08-28 16:14:38.139 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:38.140 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:38.140 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-08-28 16:14:38.140 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.140 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:38.140 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-08-28 16:14:38.141 [INFO][63] daemon.go 546: No driver process to monitor
2019-08-28 16:14:38.141 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.141 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.141 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.141 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.141 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe2b:a552":set.empty{}}}
2019-08-28 16:14:38.141 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-08-28 16:14:38.141 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.141 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-08-28 16:14:38.141 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-08-28 16:14:38.141 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.142 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.142 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-08-28 16:14:38.142 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.142 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-08-28 16:14:38.142 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-08-28 16:14:38.142 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe54:4517":set.empty{}}}
2019-08-28 16:14:38.142 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 127: Sending status update Status=resync
2019-08-28 16:14:38.142 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.142 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.143 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:38.143 [INFO][63] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-08-28 16:14:38.143 [INFO][63] watchersyncer.go 127: Sending status update Status=in-sync
2019-08-28 16:14:38.143 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-08-28 16:14:38.144 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp001,name=DefaultEndpointToHostAction) Return 8 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 236357e2b4f74b22a557c3c0ddeb3a84 6 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 102: Datamodel in sync, flushing config update
2019-08-28 16:14:38.144 [INFO][63] config_batcher.go 112: Sending config update global: map[ClusterGUID:236357e2b4f74b22a557c3c0ddeb3a84 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[DefaultEndpointToHostAction:Return].
2019-08-28 16:14:38.144 [INFO][63] async_calc_graph.go 160: First time we've been in sync
2019-08-28 16:14:38.144 [INFO][63] event_sequencer.go 210: Possible config update. global=map[string]string{"CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"236357e2b4f74b22a557c3c0ddeb3a84", "ClusterType":"k8s,bgp"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-08-28 16:14:38.145 [INFO][63] config_params.go 217: Merging in config from datastore (global): map[LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:236357e2b4f74b22a557c3c0ddeb3a84 ClusterType:k8s,bgp CalicoVersion:v3.3.2]
2019-08-28 16:14:38.145 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-08-28 16:14:38.145 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] usagerep.go 83: Waiting before first check-in delay=5m0.156s
2019-08-28 16:14:38.145 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-08-28 16:14:38.145 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-08-28 16:14:38.145 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:38.145 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-08-28 16:14:38.146 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:38.147 [INFO][63] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:38.147 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-08-28 16:14:38.147 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:38.149 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:38.149 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-08-28 16:14:38.150 [INFO][63] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-08-28 16:14:38.150 [INFO][63] daemon.go 892: Datastore now in sync.
2019-08-28 16:14:38.150 [INFO][63] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-08-28 16:14:38.150 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-08-28 16:14:38.150 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"192.168.0.0-16" pool:<cidr:"192.168.0.0/16" masquerade:true > 
2019-08-28 16:14:38.151 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fdef:bb2e:a633::-48" pool:<cidr:"fdef:bb2e:a633::/48" > 
2019-08-28 16:14:38.151 [INFO][63] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-08-28 16:14:38.151 [INFO][63] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=149.002816ms
2019-08-28 16:14:38.151 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:38.151 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.151 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.151 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.151 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.152 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.152 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-08-28 16:14:38.152 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-08-28 16:14:38.152 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-08-28 16:14:38.153 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-08-28 16:14:38.153 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:14:38.153 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:14:38.163 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=9.685959ms
2019-08-28 16:14:38.163 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=9.580934ms
2019-08-28 16:14:38.163 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-08-28 16:14:38.163 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-08-28 16:14:38.163 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-08-28 16:14:38.164 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-08-28 16:14:38.165 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-08-28 16:14:38.165 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-08-28 16:14:38.292 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:38.293 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:38.294 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:38.302 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:38.303 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:38.306 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:38.307 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:38.310 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:38.879 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=727.9026640000001
2019-08-28 16:14:38.879 [INFO][63] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.877084609
2019-08-28 16:14:39.952 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:39.952 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:39.952 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:39.953 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:39.954 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:39.955 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:39.956 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:39.961 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:39.962 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:39.962 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:39.966 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:39.967 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:39.969 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=17.142573000000002
2019-08-28 16:14:40.381 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.381 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:40.382 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:40.384 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.997709
2019-08-28 16:14:40.388 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.388 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:40.391 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:40.393 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.2697769999999995
2019-08-28 16:14:40.575 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.575 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:40.576 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:40.578 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4290700000000003
2019-08-28 16:14:40.582 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.582 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:40.583 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:40.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7844800000000003
2019-08-28 16:14:40.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:40.795 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:40.796 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4493560000000003
2019-08-28 16:14:40.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.818 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:40.821 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:40.823 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.727261
2019-08-28 16:14:40.826 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.826 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:40.827 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:40.828 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3920310000000002
2019-08-28 16:14:40.882 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:40.882 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:40.883 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:40.884 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.147473
2019-08-28 16:14:41.516 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-08-28 16:14:41.516 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:41.516 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.084608
2019-08-28 16:14:42.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:42.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:42.368 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.578709
2019-08-28 16:14:42.389 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.389 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:42.390 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:42.392 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.283743
2019-08-28 16:14:42.574 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.574 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:42.576 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:42.577 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9048350000000003
2019-08-28 16:14:42.582 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.583 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:42.584 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:42.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.838705
2019-08-28 16:14:42.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:42.795 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:42.796 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.581969
2019-08-28 16:14:42.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.818 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:42.819 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:42.822 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.702658
2019-08-28 16:14:42.825 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.825 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:42.826 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:42.828 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7973429999999997
2019-08-28 16:14:42.882 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:42.882 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:42.883 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:42.884 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.258544
2019-08-28 16:14:43.947 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-08-28 16:14:43.947 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:43.947 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.27943100000000004
2019-08-28 16:14:46.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:46.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:46.367 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9107719999999997
2019-08-28 16:14:46.388 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.389 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:46.390 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:46.392 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.501009
2019-08-28 16:14:46.574 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.575 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:46.576 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:46.577 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.838924
2019-08-28 16:14:46.582 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.582 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:46.583 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:46.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6889459999999996
2019-08-28 16:14:46.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:46.795 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:46.797 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7820560000000003
2019-08-28 16:14:46.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.818 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:46.820 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:46.821 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1896340000000003
2019-08-28 16:14:46.823 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.824 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:46.824 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:46.827 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.164164
2019-08-28 16:14:46.882 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:46.883 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:46.883 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:46.885 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.212221
2019-08-28 16:14:48.837 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:48.838 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:14:48.838 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:14:48.838 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:14:48.838 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:14:48.839 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.361313ms
2019-08-28 16:14:48.840 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.135275ms
2019-08-28 16:14:48.840 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.896075
2019-08-28 16:14:54.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:54.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:54.367 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.682093
2019-08-28 16:14:54.388 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.388 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:54.389 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:54.391 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.797675
2019-08-28 16:14:54.574 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.574 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:54.576 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:54.578 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.884366
2019-08-28 16:14:54.583 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.584 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:54.585 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:54.586 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.969191
2019-08-28 16:14:54.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:54.798 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:54.801 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.689243
2019-08-28 16:14:54.822 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.823 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:54.823 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:54.824 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:54.828 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:54.829 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.8824890000000005
2019-08-28 16:14:54.886 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:54.886 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:54.887 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:54.888 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.007071
2019-08-28 16:14:59.475 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:59.475 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:14:59.475 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:14:59.475 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:14:59.476 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:14:59.478 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.07606ms
2019-08-28 16:14:59.480 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.537754ms
2019-08-28 16:14:59.481 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.291711
2019-08-28 16:15:09.625 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:09.625 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:09.625 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:09.625 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:09.625 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:09.626 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.025456ms
2019-08-28 16:15:09.627 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.323202ms
2019-08-28 16:15:09.627 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.588147
2019-08-28 16:15:10.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:15:10.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:15:10.367 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7695950000000003
2019-08-28 16:15:10.388 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.388 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:15:10.389 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:15:10.392 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.844481
2019-08-28 16:15:10.575 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.575 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:15:10.576 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:15:10.577 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.446022
2019-08-28 16:15:10.582 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.582 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:15:10.583 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:15:10.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.539453
2019-08-28 16:15:10.793 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:15:10.795 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:15:10.796 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.572791
2019-08-28 16:15:10.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.818 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:15:10.819 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:15:10.820 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.135754
2019-08-28 16:15:10.823 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.824 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:15:10.824 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:15:10.826 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.748673
2019-08-28 16:15:10.882 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:10.882 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:15:10.883 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:15:10.885 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.471469
2019-08-28 16:15:20.567 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:20.567 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:20.567 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:20.567 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:20.567 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:20.569 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.346811ms
2019-08-28 16:15:20.570 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.290459ms
2019-08-28 16:15:20.570 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.84273
2019-08-28 16:15:30.820 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:30.821 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:30.821 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:30.825 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:30.826 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:30.827 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.478265ms
2019-08-28 16:15:30.827 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.263278ms
2019-08-28 16:15:30.827 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.380523
2019-08-28 16:15:41.571 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:41.572 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:41.572 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:41.572 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:41.572 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:41.573 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.313873ms
2019-08-28 16:15:41.574 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.796664ms
2019-08-28 16:15:41.574 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1977379999999997
2019-08-28 16:15:42.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:15:42.366 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:15:42.368 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.801279
2019-08-28 16:15:42.389 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.389 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:15:42.390 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:15:42.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.090637
2019-08-28 16:15:42.576 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.576 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:15:42.578 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:15:42.580 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6328620000000003
2019-08-28 16:15:42.583 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.583 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:15:42.585 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:15:42.586 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0660510000000003
2019-08-28 16:15:42.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:15:42.796 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:15:42.797 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8881449999999997
2019-08-28 16:15:42.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.819 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:15:42.820 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:15:42.821 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.894142
2019-08-28 16:15:42.824 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.824 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:15:42.825 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:15:42.827 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.836941
2019-08-28 16:15:42.882 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:42.882 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:15:42.884 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:15:42.886 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.476598
2019-08-28 16:15:51.622 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:51.622 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:51.622 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:51.622 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:51.622 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:51.623 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.344252ms
2019-08-28 16:15:51.624 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.604916ms
2019-08-28 16:15:51.624 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9929309999999998
2019-08-28 16:16:02.161 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:02.161 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:02.161 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:02.161 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:02.161 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:02.163 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.205235ms
2019-08-28 16:16:02.163 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.371244ms
2019-08-28 16:16:02.163 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.599675
2019-08-28 16:16:10.383 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:10.384 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:16:10.384 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:16:10.384 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.461612
2019-08-28 16:16:12.608 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:12.609 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:12.609 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:12.609 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:12.609 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:12.610 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.258121ms
2019-08-28 16:16:12.611 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.585631ms
2019-08-28 16:16:12.611 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.232589
2019-08-28 16:16:23.016 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:23.016 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:23.016 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:23.016 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:23.016 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:23.018 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.111615ms
2019-08-28 16:16:23.019 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.63994ms
2019-08-28 16:16:23.019 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.252478
2019-08-28 16:16:33.482 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:33.482 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:33.482 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:33.482 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:33.482 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:33.485 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.639578ms
2019-08-28 16:16:33.485 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.791805ms
2019-08-28 16:16:33.485 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.751466
2019-08-28 16:16:43.675 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:43.675 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:43.675 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:43.676 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:43.676 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:43.678 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.19468ms
2019-08-28 16:16:43.679 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.786778ms
2019-08-28 16:16:43.679 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.5290299999999997
2019-08-28 16:16:46.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:16:46.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:16:46.368 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.768618
2019-08-28 16:16:46.389 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.389 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:16:46.391 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:16:46.393 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7527709999999996
2019-08-28 16:16:46.575 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.575 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:16:46.577 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:16:46.582 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.913751
2019-08-28 16:16:46.586 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.587 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:16:46.588 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:16:46.589 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.771842
2019-08-28 16:16:46.794 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:16:46.797 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:16:46.800 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.651309
2019-08-28 16:16:46.821 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.821 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:16:46.821 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:46.823 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:16:46.826 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:46.829 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c"} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", ""} ipVersion=0x4 table="filter"
2019-08-28 16:16:46.829 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-08-28 16:16:46.831 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.922482
2019-08-28 16:16:46.889 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:46.889 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:46.893 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:46.897 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-08-28 16:16:46.899 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.837274
2019-08-28 16:16:47.841 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:47.841 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:47.843 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:47.846 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.037421999999999
2019-08-28 16:16:47.904 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:47.904 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:47.906 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:47.908 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6896440000000004
2019-08-28 16:16:48.835 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:48.835 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:48.837 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:48.840 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.0017059999999995
2019-08-28 16:16:48.904 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:48.904 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:48.906 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:48.908 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.899011
2019-08-28 16:16:50.835 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:50.835 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:50.837 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:50.841 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.288853
2019-08-28 16:16:50.905 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:50.906 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:50.907 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:50.911 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.938701999999999
2019-08-28 16:16:54.101 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:54.101 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:54.101 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:54.102 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:54.102 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:54.103 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.687274ms
2019-08-28 16:16:54.105 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.411679ms
2019-08-28 16:16:54.105 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.015449
2019-08-28 16:16:54.831 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:54.831 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:54.833 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:54.836 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.070845
2019-08-28 16:16:54.904 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:54.905 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:54.906 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:54.909 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.188739
2019-08-28 16:17:02.835 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:02.835 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:02.837 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:02.840 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.724997
2019-08-28 16:17:02.904 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:02.904 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:02.905 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:02.907 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.974244
2019-08-28 16:17:04.264 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:04.264 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:04.264 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:04.264 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:04.264 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:04.266 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.778852ms
2019-08-28 16:17:04.267 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.848552ms
2019-08-28 16:17:04.267 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.495087
2019-08-28 16:17:14.737 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:14.737 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:14.738 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:14.738 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:14.738 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:14.740 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.097827ms
2019-08-28 16:17:14.740 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.129612ms
2019-08-28 16:17:14.740 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7428359999999996
2019-08-28 16:17:18.831 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:18.831 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:18.833 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:18.836 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c", ""} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", "", ""} ipVersion=0x4 table="filter"
2019-08-28 16:17:18.836 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-08-28 16:17:18.836 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-08-28 16:17:18.838 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.131837
2019-08-28 16:17:18.906 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:18.906 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:18.908 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:18.910 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-08-28 16:17:18.910 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-08-28 16:17:18.912 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.125761000000001
2019-08-28 16:17:19.844 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:19.845 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:19.846 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:19.850 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.354759
2019-08-28 16:17:19.918 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:19.918 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:19.920 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:19.923 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.562072000000001
2019-08-28 16:17:20.844 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:20.844 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:20.847 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:20.850 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.975218
2019-08-28 16:17:20.918 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:20.919 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:20.920 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:20.929 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.49988
2019-08-28 16:17:22.849 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:22.849 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:22.850 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:22.852 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.041302
2019-08-28 16:17:22.915 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:22.916 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:22.917 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:22.919 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.077297
2019-08-28 16:17:24.868 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:24.868 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:24.868 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:24.871 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:24.871 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:24.873 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.396025ms
2019-08-28 16:17:24.873 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.906366ms
2019-08-28 16:17:24.873 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.236728
2019-08-28 16:17:26.838 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:26.839 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:26.841 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:26.843 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.4125
2019-08-28 16:17:26.917 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:26.917 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:26.918 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:26.920 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.81238
2019-08-28 16:17:29.903 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali2d66a766136"
2019-08-28 16:17:29.903 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{}}
2019-08-28 16:17:29.903 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{}}
2019-08-28 16:17:29.903 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{}}
2019-08-28 16:17:29.903 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.904 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.14139600000000002
2019-08-28 16:17:29.905 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali2d66a766136"
2019-08-28 16:17:29.905 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.905 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.905 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali2d66a766136", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.905 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.906 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.08258499999999999
2019-08-28 16:17:29.906 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="cali2d66a766136" state="up"
2019-08-28 16:17:29.906 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali2d66a766136", State:"up"}
2019-08-28 16:17:29.906 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.906 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.906 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.906 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.906 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.907 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.684445
2019-08-28 16:17:29.917 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-42t6m, name=eth0)
2019-08-28 16:17:29.917 [INFO][63] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"allow" rule_id:"YLdFWiauLlZiqqnX" > outbound_rules:<action:"allow" rule_id:"s12JEevpe1A9nAkJ" > > 
2019-08-28 16:17:29.918 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.919 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-42t6m" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali2d66a766136" mac:"9a:5b:f8:ec:6c:8f" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-08-28 16:17:29.919 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.919 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.919 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d66a766136" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.919 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d66a766136" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.919 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d66a766136" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d66a766136" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.920 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:29.920 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.920 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:29.925 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:29.926 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:29.931 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:29.931 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"} status="up"
2019-08-28 16:17:29.931 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.467259
2019-08-28 16:17:30.936 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:30.936 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:30.936 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:30.937 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:30.939 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:30.941 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.7908170000000005
2019-08-28 16:17:31.531 [INFO][63] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-08-28 16:17:31.933 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:31.934 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:31.934 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:31.936 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:31.938 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:31.941 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.090615
2019-08-28 16:17:33.935 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:33.948 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:33.948 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:33.950 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:33.952 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:33.953 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.721684000000001
2019-08-28 16:17:34.918 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:34.918 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:34.920 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:34.925 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.418374
2019-08-28 16:17:35.548 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:35.548 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:35.548 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:35.548 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:35.548 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:35.550 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.927923ms
2019-08-28 16:17:35.551 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.586138ms
2019-08-28 16:17:35.551 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1391280000000004
2019-08-28 16:17:37.928 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:37.929 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:37.934 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:37.937 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.031649999999999
2019-08-28 16:17:37.938 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:37.939 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:37.939 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:37.941 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4101869999999996
2019-08-28 16:17:41.204 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-42t6m, name=eth0)
2019-08-28 16:17:41.206 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-42t6m" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali2d66a766136" mac:"9a:5b:f8:ec:6c:8f" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-08-28 16:17:41.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:41.206 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.206 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d66a766136" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.207 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:41.207 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d66a766136" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali2d66a766136" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.207 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:41.207 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali2d66a766136" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali2d66a766136"
2019-08-28 16:17:41.207 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.207 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"}
2019-08-28 16:17:41.209 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:41.210 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:41.212 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:41.212 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-42t6m", EndpointId:"eth0"} status="up"
2019-08-28 16:17:41.212 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.999674
2019-08-28 16:17:44.760 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:44.760 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:17:44.760 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:17:44.767 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.18912
2019-08-28 16:17:45.935 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:45.935 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:45.935 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:45.937 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:45.938 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:45.940 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.946367
2019-08-28 16:17:46.527 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:46.527 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:46.528 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:46.528 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:46.528 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:46.529 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.674411ms
2019-08-28 16:17:46.530 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.015111ms
2019-08-28 16:17:46.530 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4963189999999997
2019-08-28 16:17:50.913 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:50.913 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:50.916 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:50.921 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.818191000000001
2019-08-28 16:17:56.899 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:56.899 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:56.899 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:56.899 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:56.900 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:56.902 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.481528ms
2019-08-28 16:17:56.903 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.279063ms
2019-08-28 16:17:56.903 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.268274
2019-08-28 16:18:01.928 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:01.929 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:18:01.931 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:18:01.934 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.175853999999999
2019-08-28 16:18:01.936 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:01.936 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:18:01.937 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:18:01.939 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.161863
2019-08-28 16:18:07.047 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:07.048 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:07.048 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:07.049 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:07.049 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:07.051 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.200108ms
2019-08-28 16:18:07.052 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.008687ms
2019-08-28 16:18:07.052 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8633080000000004
2019-08-28 16:18:16.366 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:16.366 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-08-28 16:18:16.369 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:18:16.375 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.835459
2019-08-28 16:18:16.586 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:16.586 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-08-28 16:18:16.589 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:18:16.591 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.341316
2019-08-28 16:18:16.593 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:16.593 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-08-28 16:18:16.595 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:18:16.597 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.572659
2019-08-28 16:18:16.802 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:16.802 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-08-28 16:18:16.804 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:18:16.807 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.3372649999999995
2019-08-28 16:18:16.828 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:16.828 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-08-28 16:18:16.849 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:18:16.851 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=23.045419000000003
2019-08-28 16:18:17.141 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:17.141 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:17.141 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:17.141 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:17.142 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:17.144 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.149294ms
2019-08-28 16:18:17.144 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.356787ms
2019-08-28 16:18:17.144 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.097936
2019-08-28 16:18:22.913 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:22.913 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:18:22.915 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:18:22.919 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.377986000000001
2019-08-28 16:18:27.613 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:27.613 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:27.613 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:27.613 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:27.614 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:27.615 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.754533ms
2019-08-28 16:18:27.616 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.565785ms
2019-08-28 16:18:27.616 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.034094
2019-08-28 16:18:33.929 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:33.929 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:18:33.932 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:18:33.939 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.582286
2019-08-28 16:18:33.941 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:33.941 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:18:33.942 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:18:33.944 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9511220000000002
2019-08-28 16:18:38.565 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:38.565 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:38.565 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:38.565 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:38.565 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:38.568 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.796729ms
2019-08-28 16:18:38.568 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.747958ms
2019-08-28 16:18:38.568 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.288543
2019-08-28 16:18:49.465 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:49.465 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:49.465 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:49.465 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:49.465 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:49.467 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.367049ms
2019-08-28 16:18:49.467 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.643751ms
2019-08-28 16:18:49.467 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.922209
2019-08-28 16:18:54.364 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:54.364 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:18:54.365 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:18:54.367 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.699827
2019-08-28 16:18:54.573 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:54.574 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:18:54.575 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:18:54.577 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.139954
2019-08-28 16:18:54.582 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:54.582 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:18:54.583 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:18:54.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.519906
2019-08-28 16:18:54.793 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:54.794 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:18:54.795 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:18:54.796 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.85243
2019-08-28 16:18:54.818 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:54.818 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:18:54.821 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:18:54.823 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.468718
2019-08-28 16:18:59.634 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:59.634 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:59.634 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:59.634 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:59.634 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:59.636 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.365732ms
2019-08-28 16:18:59.636 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.728274ms
2019-08-28 16:18:59.636 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.141857
2019-08-28 16:19:09.636 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:09.636 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:09.636 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:09.636 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:09.636 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:09.638 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.216819ms
2019-08-28 16:19:09.638 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.294971ms
2019-08-28 16:19:09.638 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.623499
2019-08-28 16:19:14.989 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:14.990 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:19:14.990 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:19:14.992 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.235182
2019-08-28 16:19:20.316 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:20.317 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:20.317 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:20.317 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:20.317 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:20.319 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.862022ms
2019-08-28 16:19:20.319 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.491251ms
2019-08-28 16:19:20.320 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.143923
2019-08-28 16:19:26.913 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:26.913 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:19:26.914 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:19:26.916 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.771809
2019-08-28 16:19:30.351 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:30.351 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:30.351 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:30.351 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:30.352 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:30.353 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.816295ms
2019-08-28 16:19:30.355 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.600733ms
2019-08-28 16:19:30.356 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.454158
2019-08-28 16:19:37.928 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:37.929 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:19:37.930 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:19:37.932 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2154100000000003
2019-08-28 16:19:37.934 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:37.934 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:19:37.935 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:19:37.937 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.35572
2019-08-28 16:19:38.301 [INFO][63] usagerep.go 106: Initial delay complete, doing first report
2019-08-28 16:19:38.301 [INFO][63] usagerep.go 185: Reporting cluster usage/checking for deprecation warnings. alpEnabled=false calicoVersion="v3.3.2" clusterGUID="236357e2b4f74b22a557c3c0ddeb3a84" 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-08-28 16:19:41.302 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:41.302 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:41.302 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:41.303 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:41.303 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:41.305 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.457712ms
2019-08-28 16:19:41.306 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.731056ms
2019-08-28 16:19:41.306 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.578711
2019-08-28 16:19:43.302 [INFO][63] usagerep.go 151: Failed to report usage/get deprecation warnings. error=Get https://usage.projectcalico.org/UsageCheck/calicoVersionCheck?alp=false&alp_policies=0&cal_ver=v3.3.2&guid=236357e2b4f74b22a557c3c0ddeb3a84&heps=0&policies=0&profiles=5&rev=1edd26adb1cfe5c6ff437467d429608428fbd1fe&size=3&type=k8s%2Cbgp&version=v3.3.2&weps=6: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
2019-08-28 16:19:43.302 [INFO][63] usagerep.go 108: First report done, starting ticker
2019-08-28 16:19:51.771 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:51.771 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:51.771 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:51.771 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:51.771 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:51.773 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.911762ms
2019-08-28 16:19:51.774 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.111469ms
2019-08-28 16:19:51.774 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6037730000000003
2019-08-28 16:20:02.280 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:20:02.280 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:20:02.280 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:20:02.281 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:20:02.281 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:20:02.282 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.651796ms
2019-08-28 16:20:02.282 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.393029ms
2019-08-28 16:20:02.283 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.654791
2019-08-28 16:20:12.502 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:20:12.502 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:20:12.502 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:20:12.502 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:20:12.503 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:20:12.504 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.695015ms
2019-08-28 16:20:12.504 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.586733ms
2019-08-28 16:20:12.505 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.394731
