2019-08-28 16:14:45.229 [INFO][65] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=8 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"ctl01", 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{0x4:map[string]string{"etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"ctl01", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key"}, 0x3:map[string]string{"MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None"}, 0x1:map[string]string{"ClusterGUID":"236357e2b4f74b22a557c3c0ddeb3a84", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"ClusterType":"k8s,bgp", "ReportingIntervalSecs":"0", "FelixHostname":"ctl01", "EtcdCaFile":"/var/lib/etcd/ca.pem", "LogSeverityFile":"None", "DefaultEndpointToHostAction":"Return", "ClusterGUID":"236357e2b4f74b22a557c3c0ddeb3a84", "LogSeverityScreen":"Info", "EtcdEndpoints":"https://172.16.10.36:4001", "MetadataAddr":"None", "LogFilePath":"None", "LogSeveritySys":"None", "CalicoVersion":"v3.3.2", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-08-28 16:14:45.229 [INFO][65] driver.go 43: Using internal (linux) dataplane driver.
2019-08-28 16:14:45.230 [INFO][65] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-08-28 16:14:45.230 [INFO][65] 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)(0xc4200b45a0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200b4730), 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)(0xc420174980), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-08-28 16:14:45.230 [INFO][65] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4200b45a0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200b4730), 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:45.230 [INFO][65] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-08-28 16:14:45.230 [INFO][65] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-08-28 16:14:45.230 [INFO][65] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-08-28 16:14:45.231 [INFO][65] 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:45.232 [INFO][65] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-08-28 16:14:45.232 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-08-28 16:14:45.233 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-08-28 16:14:45.234 [INFO][65] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-08-28 16:14:45.234 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-08-28 16:14:45.234 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-08-28 16:14:45.234 [INFO][65] int_dataplane.go 424: Registering to report health.
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.235 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.236 [INFO][65] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.236 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.237 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-08-28 16:14:45.237 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-08-28 16:14:45.237 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-08-28 16:14:45.237 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-08-28 16:14:45.237 [INFO][65] daemon.go 299: Connect to the dataplane driver.
2019-08-28 16:14:45.237 [INFO][65] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc420418200), (*watchersyncer.watcherCache)(0xc420418280), (*watchersyncer.watcherCache)(0xc420418300), (*watchersyncer.watcherCache)(0xc420418380), (*watchersyncer.watcherCache)(0xc420418400), (*watchersyncer.watcherCache)(0xc420418480), (*watchersyncer.watcherCache)(0xc420418500), (*watchersyncer.watcherCache)(0xc420418580), (*watchersyncer.watcherCache)(0xc420418600), (*watchersyncer.watcherCache)(0xc420418680)}, results:(chan interface {})(0xc4201a6c60), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42000c0e0), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-08-28 16:14:45.237 [INFO][65] calc_graph.go 96: Creating calculation graph, filtered to hostname ctl01
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.237 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:45.238 [INFO][65] iface_monitor.go 88: Interface monitoring thread started.
2019-08-28 16:14:45.238 [INFO][65] iface_monitor.go 95: Subscribed to netlink updates.
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 981: Started internal status report thread
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 983: Process status reports disabled
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-08-28 16:14:45.238 [INFO][65] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-08-28 16:14:45.238 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-08-28 16:14:45.239 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:45.239 [INFO][65] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-08-28 16:14:45.239 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"::1":set.empty{}, "127.0.0.1":set.empty{}} ifaceName="lo"
2019-08-28 16:14:45.239 [INFO][65] daemon.go 439: Starting the datastore Syncer
2019-08-28 16:14:45.239 [INFO][65] watchersyncer.go 89: Start called
2019-08-28 16:14:45.239 [INFO][65] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-08-28 16:14:45.239 [INFO][65] async_calc_graph.go 134: AsyncCalcGraph running
2019-08-28 16:14:45.239 [INFO][65] 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:45.239 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-08-28 16:14:45.240 [INFO][65] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-08-28 16:14:45.240 [INFO][65] 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:45.240 [INFO][65] watchersyncer.go 147: Starting main event processing loop
2019-08-28 16:14:45.240 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.240 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe3f:9b0c":set.empty{}, "192.168.11.21":set.empty{}} ifaceName="ens3"
2019-08-28 16:14:45.240 [INFO][65] 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:45.241 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-08-28 16:14:45.241 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.241 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe2c:cdbc":set.empty{}} ifaceName="ens4"
2019-08-28 16:14:45.239 [INFO][65] daemon.go 454: Started the processing graph
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe3f:9b0c":set.empty{}, "192.168.11.21":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe3f:9b0c":set.empty{}, "192.168.11.21":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}} ifaceName="ens5"
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe3f:9b0c":set.empty{}, "192.168.11.21":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2c:cdbc":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2c:cdbc":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe2c:cdbc":set.empty{}} ifaceName="br-mgmt"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe2c:cdbc":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.242 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}} ifaceName="ens5.1000"
2019-08-28 16:14:45.242 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.242 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:45.243 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-08-28 16:14:45.243 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-08-28 16:14:45.243 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe2c:cdbc":set.empty{}}}
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe2c:cdbc":set.empty{}, "172.16.10.36":set.empty{}}}
2019-08-28 16:14:45.243 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe2c:cdbc":set.empty{}}}
2019-08-28 16:14:45.243 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-08-28 16:14:45.243 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.243 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.243 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe9e:c5f6":set.empty{}}}
2019-08-28 16:14:45.244 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-08-28 16:14:45.244 [INFO][65] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-08-28 16:14:45.244 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-08-28 16:14:45.244 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-08-28 16:14:45.244 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-08-28 16:14:45.244 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-08-28 16:14:45.244 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-08-28 16:14:45.244 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-08-28 16:14:45.244 [INFO][65] daemon.go 813: Reading from dataplane driver pipe...
2019-08-28 16:14:45.244 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-08-28 16:14:45.244 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-08-28 16:14:45.244 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-08-28 16:14:45.244 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.244 [INFO][65] watchersyncer.go 127: Sending status update Status=resync
2019-08-28 16:14:45.244 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.244 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.244 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.245 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.245 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.245 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.245 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-08-28 16:14:45.245 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.246 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-08-28 16:14:45.246 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.246 [INFO][65] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 236357e2b4f74b22a557c3c0ddeb3a84 6 0s} 1}
2019-08-28 16:14:45.246 [INFO][65] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-08-28 16:14:45.246 [INFO][65] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-08-28 16:14:45.246 [INFO][65] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-08-28 16:14:45.246 [INFO][65] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-08-28 16:14:45.247 [INFO][65] config_batcher.go 61: Host config update for this host: {{HostConfig(node=ctl01,name=DefaultEndpointToHostAction) Return 12 0s} 1}
2019-08-28 16:14:45.245 [INFO][65] daemon.go 546: No driver process to monitor
2019-08-28 16:14:45.245 [INFO][65] 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:"ctl01" > 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:45.247 [INFO][65] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-08-28 16:14:45.247 [INFO][65] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-08-28 16:14:45.247 [INFO][65] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-08-28 16:14:45.247 [INFO][65] watchersyncer.go 127: Sending status update Status=in-sync
2019-08-28 16:14:45.247 [INFO][65] config_batcher.go 102: Datamodel in sync, flushing config update
2019-08-28 16:14:45.247 [INFO][65] config_batcher.go 112: Sending config update global: map[LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:236357e2b4f74b22a557c3c0ddeb3a84 ClusterType:k8s,bgp CalicoVersion:v3.3.2], host: map[DefaultEndpointToHostAction:Return].
2019-08-28 16:14:45.247 [INFO][65] async_calc_graph.go 160: First time we've been in sync
2019-08-28 16:14:45.247 [INFO][65] 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:45.247 [INFO][65] config_params.go 217: Merging in config from datastore (global): map[CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:236357e2b4f74b22a557c3c0ddeb3a84 ClusterType:k8s,bgp]
2019-08-28 16:14:45.247 [INFO][65] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-08-28 16:14:45.248 [INFO][65] usagerep.go 83: Waiting before first check-in delay=5m2.382s
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.248 [INFO][65] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-08-28 16:14:45.248 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-08-28 16:14:45.249 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-08-28 16:14:45.249 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-08-28 16:14:45.249 [INFO][65] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-08-28 16:14:45.249 [INFO][65] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.250 [INFO][65] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-08-28 16:14:45.250 [INFO][65] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-08-28 16:14:45.251 [INFO][65] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for ClusterGUID: 236357e2b4f74b22a557c3c0ddeb3a84 (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-08-28 16:14:45.252 [INFO][65] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-08-28 16:14:45.252 [INFO][65] 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:45.252 [INFO][65] daemon.go 892: Datastore now in sync.
2019-08-28 16:14:45.253 [INFO][65] 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:45.253 [INFO][65] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-08-28 16:14:45.253 [INFO][65] 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:45.253 [INFO][65] 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:45.253 [INFO][65] 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:45.253 [INFO][65] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-08-28 16:14:45.253 [INFO][65] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=144.928586ms
2019-08-28 16:14:45.253 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.253 [INFO][65] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-08-28 16:14:45.253 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.254 [INFO][65] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-08-28 16:14:45.254 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-08-28 16:14:45.254 [INFO][65] route_table.go 199: Trying to connect to netlink
2019-08-28 16:14:45.254 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:14:45.254 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:14:45.254 [INFO][65] route_table.go 199: Trying to connect to netlink
2019-08-28 16:14:45.268 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=13.224562ms
2019-08-28 16:14:45.268 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-08-28 16:14:45.268 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-08-28 16:14:45.268 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-08-28 16:14:45.269 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=14.950767ms
2019-08-28 16:14:45.272 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-08-28 16:14:45.272 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-08-28 16:14:45.272 [INFO][65] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-08-28 16:14:45.417 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:45.418 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:45.420 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:45.421 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:45.422 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:45.426 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:45.428 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:45.429 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:45.973 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=720.234525
2019-08-28 16:14:45.973 [INFO][65] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.865298434
2019-08-28 16:14:47.054 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:47.054 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:47.055 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:47.056 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:47.059 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:47.060 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:47.061 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:47.062 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:47.064 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:47.065 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:47.067 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=13.351656
2019-08-28 16:14:47.510 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.510 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:47.511 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:47.512 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.425887
2019-08-28 16:14:47.520 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.520 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:47.521 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:47.522 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.732482
2019-08-28 16:14:47.546 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.546 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:47.547 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:47.549 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7200089999999997
2019-08-28 16:14:47.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.751 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:47.751 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:47.753 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.922131
2019-08-28 16:14:47.784 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.784 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:47.785 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:47.787 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.430644
2019-08-28 16:14:47.934 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.934 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:47.935 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:47.937 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3043069999999997
2019-08-28 16:14:47.942 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.942 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:47.943 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:47.944 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4167479999999997
2019-08-28 16:14:47.976 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:47.976 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:47.976 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:47.978 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.051387
2019-08-28 16:14:49.498 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.498 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:49.499 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:49.501 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.380376
2019-08-28 16:14:49.519 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.520 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:49.522 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:49.523 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.526272
2019-08-28 16:14:49.548 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.548 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:49.549 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:49.551 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.609714
2019-08-28 16:14:49.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.751 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:49.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:49.755 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8441389999999998
2019-08-28 16:14:49.786 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.787 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:49.788 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:49.791 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.378676
2019-08-28 16:14:49.936 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.936 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:49.938 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:49.940 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.5037409999999998
2019-08-28 16:14:49.943 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.943 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:49.945 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:49.947 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.03972
2019-08-28 16:14:49.977 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:49.977 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:49.978 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:49.979 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9586500000000002
2019-08-28 16:14:53.498 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.498 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:14:53.499 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:14:53.501 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.541237
2019-08-28 16:14:53.520 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.520 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:14:53.521 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:14:53.522 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1672890000000002
2019-08-28 16:14:53.547 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.547 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:14:53.548 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:14:53.549 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.301111
2019-08-28 16:14:53.750 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.750 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:14:53.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:14:53.753 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.706455
2019-08-28 16:14:53.785 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.787 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:14:53.789 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:14:53.791 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.949452
2019-08-28 16:14:53.935 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.935 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:14:53.937 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:14:53.938 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.893427
2019-08-28 16:14:53.942 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.943 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:14:53.944 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:14:53.945 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.646598
2019-08-28 16:14:53.976 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:53.976 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:14:53.977 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:14:53.978 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.583636
2019-08-28 16:14:55.933 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:14:55.933 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:14:55.933 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:14:55.933 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:14:55.933 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:14:55.934 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.232602ms
2019-08-28 16:14:55.935 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.391193ms
2019-08-28 16:14:55.935 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.937648
2019-08-28 16:15:01.496 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.496 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:15:01.498 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:15:01.499 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7479489999999998
2019-08-28 16:15:01.520 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.520 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:15:01.521 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:15:01.522 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.751476
2019-08-28 16:15:01.546 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.546 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:15:01.547 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:15:01.549 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.74515
2019-08-28 16:15:01.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.751 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:15:01.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:15:01.753 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2508760000000003
2019-08-28 16:15:01.785 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.785 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:15:01.786 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:15:01.787 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1725920000000003
2019-08-28 16:15:01.934 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.934 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:15:01.935 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:15:01.937 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.41919
2019-08-28 16:15:01.942 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.942 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:15:01.943 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:15:01.944 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.414177
2019-08-28 16:15:01.975 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:01.976 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:15:01.976 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:15:01.978 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.145964
2019-08-28 16:15:05.988 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:05.989 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:05.989 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:05.989 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:05.989 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:05.990 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.661555ms
2019-08-28 16:15:05.991 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.354695ms
2019-08-28 16:15:05.991 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.823715
2019-08-28 16:15:16.050 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:16.050 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:16.050 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:16.050 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:16.050 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:16.053 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.254328ms
2019-08-28 16:15:16.053 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.880628ms
2019-08-28 16:15:16.054 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.592813
2019-08-28 16:15:17.497 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.497 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:15:17.498 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:15:17.504 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.2218350000000004
2019-08-28 16:15:17.524 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.525 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:15:17.526 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:15:17.527 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.698097
2019-08-28 16:15:17.547 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.548 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:15:17.549 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:15:17.551 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.635242
2019-08-28 16:15:17.752 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.752 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:15:17.753 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:15:17.755 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6832879999999997
2019-08-28 16:15:17.786 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.786 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:15:17.788 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:15:17.790 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.2399949999999995
2019-08-28 16:15:17.936 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.936 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:15:17.938 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:15:17.941 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.492456
2019-08-28 16:15:17.944 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.945 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:15:17.947 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:15:17.949 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.374687000000001
2019-08-28 16:15:17.977 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:17.978 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:15:17.980 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:15:17.981 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.858893
2019-08-28 16:15:26.260 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:26.260 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:26.260 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:26.260 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:26.260 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:26.262 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.604131ms
2019-08-28 16:15:26.262 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.812685ms
2019-08-28 16:15:26.262 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.257077
2019-08-28 16:15:36.346 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:36.346 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:36.346 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:36.346 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:36.347 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:36.348 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.928602ms
2019-08-28 16:15:36.350 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.656035ms
2019-08-28 16:15:36.351 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.593629999999999
2019-08-28 16:15:47.157 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:47.157 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:47.157 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:47.157 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:47.157 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:47.158 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.417274ms
2019-08-28 16:15:47.158 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.163969ms
2019-08-28 16:15:47.158 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.7945529999999998
2019-08-28 16:15:49.496 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.497 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:15:49.498 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:15:49.500 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.3590540000000004
2019-08-28 16:15:49.521 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.521 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:15:49.522 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:15:49.526 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.38624
2019-08-28 16:15:49.550 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.550 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:15:49.551 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:15:49.553 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.292566
2019-08-28 16:15:49.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.751 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:15:49.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:15:49.754 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.726416
2019-08-28 16:15:49.785 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.785 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:15:49.786 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:15:49.788 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7018720000000003
2019-08-28 16:15:49.935 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.935 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:15:49.937 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:15:49.939 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.038913
2019-08-28 16:15:49.943 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.943 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:15:49.944 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:15:49.949 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.439348
2019-08-28 16:15:49.979 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:49.979 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:15:49.980 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:15:49.982 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.852473
2019-08-28 16:15:57.997 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:15:57.997 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:15:57.997 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:15:57.997 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:15:57.997 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:15:57.999 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.362635ms
2019-08-28 16:15:57.999 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.253677ms
2019-08-28 16:15:58.000 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.653955
2019-08-28 16:16:08.367 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:08.367 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:08.368 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:08.368 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:08.368 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:08.370 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.336422ms
2019-08-28 16:16:08.370 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.226083ms
2019-08-28 16:16:08.371 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.266578
2019-08-28 16:16:19.336 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:19.336 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:19.336 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:19.336 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:19.336 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:19.337 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.058319ms
2019-08-28 16:16:19.338 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.812072ms
2019-08-28 16:16:19.338 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.096348
2019-08-28 16:16:21.787 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:21.787 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:16:21.787 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:16:21.791 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.778189
2019-08-28 16:16:30.080 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:30.080 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:30.080 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:30.080 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:30.080 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:30.081 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.02469ms
2019-08-28 16:16:30.082 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.421787ms
2019-08-28 16:16:30.082 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.824493
2019-08-28 16:16:40.856 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:40.856 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:40.856 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:40.856 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:40.856 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:40.857 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=999.83µs
2019-08-28 16:16:40.857 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.177988ms
2019-08-28 16:16:40.857 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.488982
2019-08-28 16:16:51.713 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:51.714 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:16:51.714 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:16:51.714 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:16:51.714 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:16:51.716 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.925166ms
2019-08-28 16:16:51.716 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.680287ms
2019-08-28 16:16:51.716 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5557179999999997
2019-08-28 16:16:53.496 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.497 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:16:53.498 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:16:53.500 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.313271
2019-08-28 16:16:53.521 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.521 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:16:53.522 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:16:53.523 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.545015
2019-08-28 16:16:53.547 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.547 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:16:53.548 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:16:53.550 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.619498
2019-08-28 16:16:53.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.751 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:16:53.752 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:16:53.754 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.006928
2019-08-28 16:16:53.785 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.786 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:53.787 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:53.789 [WARNING][65] 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:53.790 [WARNING][65] 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:53.792 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.771419
2019-08-28 16:16:53.939 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.939 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:16:53.939 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:16:53.942 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.134694
2019-08-28 16:16:53.943 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.943 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:16:53.944 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:16:53.946 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.210302
2019-08-28 16:16:53.976 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:53.977 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:53.978 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:53.980 [WARNING][65] 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:53.982 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.159384
2019-08-28 16:16:54.797 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:54.798 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:54.799 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:54.801 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.524162
2019-08-28 16:16:54.985 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:54.985 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:54.987 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:55.000 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=14.553495
2019-08-28 16:16:55.806 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:55.807 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:55.808 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:55.816 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.194277000000001
2019-08-28 16:16:55.991 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:55.991 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:55.992 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:55.993 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.202004
2019-08-28 16:16:57.794 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:57.795 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:16:57.796 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:16:57.798 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.825272
2019-08-28 16:16:57.985 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:16:57.986 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:16:57.988 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:16:57.991 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.269712
2019-08-28 16:17:01.797 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:01.798 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:01.800 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:01.803 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.531266
2019-08-28 16:17:01.987 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:01.987 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:01.989 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:01.991 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.140582
2019-08-28 16:17:02.084 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:02.084 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:02.084 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:02.084 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:02.085 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:02.086 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.618561ms
2019-08-28 16:17:02.086 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.423057ms
2019-08-28 16:17:02.086 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2236170000000004
2019-08-28 16:17:09.792 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:09.792 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:09.794 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:09.796 [WARNING][65] 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:09.796 [WARNING][65] 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:09.796 [WARNING][65] 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:09.798 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.584517
2019-08-28 16:17:09.987 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:09.988 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:09.989 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:09.993 [WARNING][65] 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:09.993 [WARNING][65] 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:09.995 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.403026
2019-08-28 16:17:10.805 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:10.806 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:10.807 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:10.811 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.0876790000000005
2019-08-28 16:17:11.000 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:11.000 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:11.001 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:11.005 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.451484000000001
2019-08-28 16:17:11.804 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:11.805 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:11.806 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:11.808 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9051989999999996
2019-08-28 16:17:11.998 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:11.998 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:12.000 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:12.002 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.570711
2019-08-28 16:17:12.949 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:12.950 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:12.950 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:12.950 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:12.950 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:12.951 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.114035ms
2019-08-28 16:17:12.951 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.289855ms
2019-08-28 16:17:12.951 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.59471
2019-08-28 16:17:13.798 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:13.798 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:13.800 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:13.801 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.017095
2019-08-28 16:17:13.998 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:13.998 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:13.999 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:14.002 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.593326
2019-08-28 16:17:17.802 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:17.802 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:17.803 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:17.804 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.711091
2019-08-28 16:17:17.998 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:17.998 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:17.999 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:18.001 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.926491
2019-08-28 16:17:23.199 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:23.199 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:23.199 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:23.199 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:23.199 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:23.201 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.831566ms
2019-08-28 16:17:23.201 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.067084ms
2019-08-28 16:17:23.202 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4721349999999997
2019-08-28 16:17:25.798 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:25.799 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:25.800 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:25.802 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.67226
2019-08-28 16:17:25.999 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:25.999 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:26.001 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:26.005 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.824544
2019-08-28 16:17:28.840 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.840 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{}}
2019-08-28 16:17:28.841 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{}}
2019-08-28 16:17:28.841 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{}}
2019-08-28 16:17:28.841 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:28.841 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.136356
2019-08-28 16:17:28.842 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="cali8d00ca21f5c" state="up"
2019-08-28 16:17:28.842 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.842 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali8d00ca21f5c", State:"up"}
2019-08-28 16:17:28.842 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:28.842 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.842 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.842 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.842 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.843 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.9804959999999999
2019-08-28 16:17:28.843 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:28.843 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:28.843 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8d00ca21f5c", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:28.843 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:28.843 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.108441
2019-08-28 16:17:28.848 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-ggnhh, name=eth0)
2019-08-28 16:17:28.848 [WARNING][65] active_rules_calculator.go 326: Profile not known or invalid, generating dummy profile that drops all traffic. profileID="calico-k8s-network"
2019-08-28 16:17:28.848 [INFO][65] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"deny" rule_id:"oj2OqMy9CAebzGBO" > outbound_rules:<action:"deny" rule_id:"Eaor-oJ4HE6fBT4g" > > 
2019-08-28 16:17:28.848 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-ggnhh" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali8d00ca21f5c" mac:"62:86:da:fd:c8:37" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-08-28 16:17:28.849 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali8d00ca21f5c" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali8d00ca21f5c" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.849 [INFO][65] 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-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali8d00ca21f5c" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali8d00ca21f5c" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.849 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:28.850 [INFO][65] 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-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.850 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:28.851 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:28.853 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:28.858 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:28.858 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"} status="up"
2019-08-28 16:17:28.858 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.923253
2019-08-28 16:17:28.858 [INFO][65] 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:28.858 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.858 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:28.858 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-08-28 16:17:28.858 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.858 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:28.858 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-08-28 16:17:28.858 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:28.859 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:28.860 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:28.866 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.793073000000001
2019-08-28 16:17:29.756 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.756 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{}}
2019-08-28 16:17:29.757 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{}}
2019-08-28 16:17:29.757 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{}}
2019-08-28 16:17:29.757 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.757 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.131195
2019-08-28 16:17:29.759 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="cali074dcc11f9e" state="up"
2019-08-28 16:17:29.759 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.759 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali074dcc11f9e", State:"up"}
2019-08-28 16:17:29.759 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.759 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.759 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.759 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.760 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.760 [INFO][65] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.1/32 ifaceName="cali074dcc11f9e" ipVersion=0x4
2019-08-28 16:17:29.760 [INFO][65] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali074dcc11f9e" ipVersion=0x4
2019-08-28 16:17:29.760 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.974236
2019-08-28 16:17:29.760 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.760 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.760 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali074dcc11f9e", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.760 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.761 [INFO][65] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.1/32 ifaceName="cali074dcc11f9e" ipVersion=0x4
2019-08-28 16:17:29.761 [INFO][65] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali074dcc11f9e" ipVersion=0x4
2019-08-28 16:17:29.761 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.47997399999999996
2019-08-28 16:17:29.764 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-6cm5z, name=eth0)
2019-08-28 16:17:29.764 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-6cm5z" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali074dcc11f9e" mac:"b2:54:5c:f8:94:6d" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-08-28 16:17:29.764 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.764 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.764 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali074dcc11f9e" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.764 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:29.765 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali074dcc11f9e" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.765 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.765 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.765 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.765 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.766 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.767 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.767 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.767 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali074dcc11f9e" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.767 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:29.767 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali074dcc11f9e" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.767 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.767 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.767 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.767 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:29.767 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.767 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:29.768 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:29.769 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:29.777 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-08-28 16:17:29.777 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"} status="up"
2019-08-28 16:17:29.777 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=13.008799
2019-08-28 16:17:29.984 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calib4eb019900f"
2019-08-28 16:17:29.984 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{}}
2019-08-28 16:17:29.984 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{}}
2019-08-28 16:17:29.984 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{}}
2019-08-28 16:17:29.984 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.984 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.152586
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calib4eb019900f"
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 471: Linux interface state changed. ifaceName="calib4eb019900f" state="up"
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.986 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.986 [INFO][65] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib4eb019900f", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.079673
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calib4eb019900f", State:"up"}
2019-08-28 16:17:29.986 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.986 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.986 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.987 [INFO][65] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.987 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.987 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.1265209999999999
2019-08-28 16:17:29.992 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-lq5jp, name=eth0)
2019-08-28 16:17:29.992 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-lq5jp" endpoint_id:"eth0" > endpoint:<state:"active" name:"calib4eb019900f" mac:"42:69:35:2d:67:55" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-08-28 16:17:29.992 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:29.992 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.992 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-calib4eb019900f" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.992 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:29.992 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-calib4eb019900f" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.992 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.992 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.992 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-08-28 16:17:29.992 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.992 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.992 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.993 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.993 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-calib4eb019900f" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.993 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:29.993 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-calib4eb019900f" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.993 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.993 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.993 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-08-28 16:17:29.993 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:29.993 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.993 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:29.995 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:29.996 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:30.004 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:30.004 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"} status="up"
2019-08-28 16:17:30.004 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=12.344904
2019-08-28 16:17:30.536 [INFO][65] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-08-28 16:17:31.014 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:31.014 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:31.014 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:31.015 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:31.016 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:31.018 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.1753670000000005
2019-08-28 16:17:31.052 [INFO][65] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-08-28 16:17:31.464 [INFO][65] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=10
2019-08-28 16:17:32.007 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:32.007 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:32.008 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:32.009 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:32.010 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:32.012 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.110732
2019-08-28 16:17:33.468 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:33.468 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:33.468 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:33.468 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:33.468 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:33.471 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.008464ms
2019-08-28 16:17:33.471 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.523274ms
2019-08-28 16:17:33.471 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.083616
2019-08-28 16:17:34.003 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:34.003 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:34.006 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:34.009 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.180604
2019-08-28 16:17:34.009 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:34.009 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:34.011 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:34.013 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.564004
2019-08-28 16:17:38.006 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:38.007 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:38.007 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:38.008 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:38.010 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:38.012 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.405015
2019-08-28 16:17:41.192 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-6cm5z, name=eth0)
2019-08-28 16:17:41.192 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-6cm5z" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali074dcc11f9e" mac:"b2:54:5c:f8:94:6d" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-08-28 16:17:41.192 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:41.192 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.192 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali074dcc11f9e" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.192 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:41.192 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali074dcc11f9e" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.192 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.193 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:41.193 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.193 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.193 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.193 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali074dcc11f9e" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.193 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:41.193 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali074dcc11f9e" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.193 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.193 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali074dcc11f9e"
2019-08-28 16:17:41.194 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.194 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"}
2019-08-28 16:17:41.199 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:41.200 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:41.202 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:41.202 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6cm5z", EndpointId:"eth0"} status="up"
2019-08-28 16:17:41.202 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.885217
2019-08-28 16:17:41.442 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-ggnhh, name=eth0)
2019-08-28 16:17:41.443 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-ggnhh" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali8d00ca21f5c" mac:"62:86:da:fd:c8:37" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-08-28 16:17:41.443 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:41.443 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.443 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali8d00ca21f5c" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.443 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:41.443 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali8d00ca21f5c" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.443 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.443 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:41.444 [INFO][65] 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-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.444 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.444 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.444 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-cali8d00ca21f5c" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.444 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:41.444 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-cali8d00ca21f5c" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.445 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.445 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8d00ca21f5c"
2019-08-28 16:17:41.445 [INFO][65] 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-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.445 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"}
2019-08-28 16:17:41.446 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:41.448 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:41.450 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:41.450 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-ggnhh", EndpointId:"eth0"} status="up"
2019-08-28 16:17:41.450 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.957598
2019-08-28 16:17:41.458 [INFO][65] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-lq5jp, name=eth0)
2019-08-28 16:17:41.458 [INFO][65] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-lq5jp" endpoint_id:"eth0" > endpoint:<state:"active" name:"calib4eb019900f" mac:"42:69:35:2d:67:55" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-08-28 16:17:41.458 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:41.458 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.458 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-calib4eb019900f" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.458 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-08-28 16:17:41.458 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-calib4eb019900f" ipVersion=0x4 table="filter"
2019-08-28 16:17:41.458 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.459 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:41.459 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.460 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.460 [INFO][65] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.460 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-tw-calib4eb019900f" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.460 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-08-28 16:17:41.460 [INFO][65] table.go 417: Queueing update of chain. chainName="cali-fw-calib4eb019900f" ipVersion=0x6 table="filter"
2019-08-28 16:17:41.460 [INFO][65] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.460 [INFO][65] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib4eb019900f"
2019-08-28 16:17:41.460 [INFO][65] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.460 [INFO][65] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"}
2019-08-28 16:17:41.461 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:41.464 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:41.468 [INFO][65] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-08-28 16:17:41.468 [INFO][65] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-lq5jp", EndpointId:"eth0"} status="up"
2019-08-28 16:17:41.468 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.208955000000001
2019-08-28 16:17:42.003 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:42.004 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:17:42.005 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:17:42.007 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.326111
2019-08-28 16:17:44.144 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:44.144 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:44.144 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:44.144 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:44.144 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:44.145 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.078218ms
2019-08-28 16:17:44.145 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.114193ms
2019-08-28 16:17:44.145 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.424673
2019-08-28 16:17:46.003 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:46.003 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:17:46.005 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:17:46.008 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.188911
2019-08-28 16:17:46.009 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:46.009 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:17:46.011 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:17:46.013 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.606992
2019-08-28 16:17:54.366 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:54.366 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:17:54.366 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:17:54.366 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:17:54.366 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:17:54.368 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.54047ms
2019-08-28 16:17:54.368 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.896753ms
2019-08-28 16:17:54.368 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2482
2019-08-28 16:17:57.029 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:17:57.029 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:17:57.029 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:17:57.035 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.751054
2019-08-28 16:18:02.008 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:02.009 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:18:02.009 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:18:02.011 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:18:02.013 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:18:02.017 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.829507
2019-08-28 16:18:05.286 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:05.286 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:05.286 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:05.286 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:05.286 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:05.288 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.982231ms
2019-08-28 16:18:05.289 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.326166ms
2019-08-28 16:18:05.289 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.729672
2019-08-28 16:18:13.995 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:13.996 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:18:13.998 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:18:14.002 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.676305
2019-08-28 16:18:15.364 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:15.365 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:15.365 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:15.365 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:15.365 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:15.367 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.245367ms
2019-08-28 16:18:15.368 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.091073ms
2019-08-28 16:18:15.368 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.697303
2019-08-28 16:18:23.498 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:23.499 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-08-28 16:18:23.501 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:18:23.505 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.183018000000001
2019-08-28 16:18:23.528 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:23.528 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-08-28 16:18:23.530 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:18:23.532 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.211774
2019-08-28 16:18:23.757 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:23.757 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-08-28 16:18:23.759 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:18:23.763 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.951916
2019-08-28 16:18:23.945 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:23.946 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-08-28 16:18:23.946 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-08-28 16:18:23.947 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:18:23.950 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:18:23.952 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.315038
2019-08-28 16:18:26.252 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:26.252 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:26.252 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:26.252 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:26.252 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:26.253 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.580534ms
2019-08-28 16:18:26.253 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.128206ms
2019-08-28 16:18:26.254 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.068152
2019-08-28 16:18:34.003 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:34.004 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:18:34.006 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:18:34.010 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.238218
2019-08-28 16:18:34.010 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:34.010 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:18:34.012 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:18:34.015 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.039287
2019-08-28 16:18:36.842 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:36.842 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:36.842 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:36.842 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:36.843 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:36.844 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.647006ms
2019-08-28 16:18:36.845 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.586225ms
2019-08-28 16:18:36.846 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.65997
2019-08-28 16:18:46.963 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:46.964 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:46.964 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:46.964 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:46.964 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:46.966 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.403148ms
2019-08-28 16:18:46.967 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.606491ms
2019-08-28 16:18:46.967 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.667037
2019-08-28 16:18:56.989 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:18:56.989 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:18:56.989 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:18:56.989 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:18:56.990 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:18:56.991 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.595705ms
2019-08-28 16:18:56.991 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.716168ms
2019-08-28 16:18:56.991 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.107008
2019-08-28 16:19:01.497 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:01.497 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-08-28 16:19:01.499 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-08-28 16:19:01.502 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.202351
2019-08-28 16:19:01.522 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:01.523 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-08-28 16:19:01.524 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-08-28 16:19:01.526 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4203240000000004
2019-08-28 16:19:01.751 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:01.752 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-08-28 16:19:01.756 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-08-28 16:19:01.758 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.752319
2019-08-28 16:19:01.938 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:01.938 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-08-28 16:19:01.940 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-08-28 16:19:01.943 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.6356399999999995
2019-08-28 16:19:01.944 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:01.944 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-08-28 16:19:01.946 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-08-28 16:19:01.949 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.951733
2019-08-28 16:19:07.521 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:07.521 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:07.521 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:07.521 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:07.521 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:07.524 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.801097ms
2019-08-28 16:19:07.524 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.172971ms
2019-08-28 16:19:07.524 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.405221
2019-08-28 16:19:17.845 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:17.845 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:17.845 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:17.845 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:17.845 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:17.847 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.008351ms
2019-08-28 16:19:17.848 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.739389ms
2019-08-28 16:19:17.848 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.163366
2019-08-28 16:19:17.995 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:17.995 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-08-28 16:19:17.996 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-08-28 16:19:17.998 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.597441
2019-08-28 16:19:27.669 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:27.669 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-08-28 16:19:27.669 [INFO][65] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-08-28 16:19:27.672 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.901103
2019-08-28 16:19:28.765 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:28.765 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:28.765 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:28.765 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:28.765 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:28.766 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.157062ms
2019-08-28 16:19:28.766 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.170033ms
2019-08-28 16:19:28.766 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.767044
2019-08-28 16:19:38.003 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:38.003 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-08-28 16:19:38.005 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-08-28 16:19:38.009 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.616315999999999
2019-08-28 16:19:38.010 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:38.010 [INFO][65] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-08-28 16:19:38.011 [INFO][65] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-08-28 16:19:38.013 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.533212
2019-08-28 16:19:39.001 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:39.001 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:39.001 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:39.001 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:39.001 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:39.002 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.304873ms
2019-08-28 16:19:39.002 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.309231ms
2019-08-28 16:19:39.003 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.662366
2019-08-28 16:19:47.630 [INFO][65] usagerep.go 106: Initial delay complete, doing first report
2019-08-28 16:19:47.630 [INFO][65] 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:49.242 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:49.242 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:49.242 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:49.242 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:49.242 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:49.244 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.480721ms
2019-08-28 16:19:49.244 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.154677ms
2019-08-28 16:19:49.244 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.59229
2019-08-28 16:19:52.631 [INFO][65] 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:52.631 [INFO][65] usagerep.go 108: First report done, starting ticker
2019-08-28 16:19:59.800 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:19:59.800 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:19:59.800 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:19:59.800 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:19:59.801 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:19:59.802 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.033195ms
2019-08-28 16:19:59.803 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.955644ms
2019-08-28 16:19:59.803 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.147601
2019-08-28 16:20:10.068 [INFO][65] int_dataplane.go 751: Applying dataplane updates
2019-08-28 16:20:10.069 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-08-28 16:20:10.069 [INFO][65] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-08-28 16:20:10.069 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-08-28 16:20:10.069 [INFO][65] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-08-28 16:20:10.071 [INFO][65] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.36743ms
2019-08-28 16:20:10.072 [INFO][65] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.820844ms
2019-08-28 16:20:10.072 [INFO][65] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.367217
