2019-10-26 13:59:20.630 [INFO][63] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp002", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"77e3fde152bc47f88c962d00f5907118", ClusterType:"k8s,bgp", CalicoVersion:"v3.3.2", ExternalNodesCIDRList:[]string(nil), DebugMemoryProfilePath:"", DebugCPUProfilePath:"/tmp/felix-cpu-<timestamp>.pprof", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, sourceToRawConfig:map[config.Source]map[string]string{0x3:map[string]string{"LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None"}, 0x1:map[string]string{"ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}, 0x4:map[string]string{"etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"cmp002"}}, rawValues:map[string]string{"EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdCaFile":"/var/lib/etcd/ca.pem", "MetadataAddr":"None", "LogSeverityFile":"None", "DefaultEndpointToHostAction":"Return", "LogSeverityScreen":"Info", "EtcdEndpoints":"https://172.16.10.36:4001", "FelixHostname":"cmp002", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "ClusterType":"k8s,bgp", "ReportingIntervalSecs":"0", "LogFilePath":"None", "LogSeveritySys":"None", "CalicoVersion":"v3.3.2"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-10-26 13:59:20.632 [INFO][63] driver.go 43: Using internal (linux) dataplane driver.
2019-10-26 13:59:20.632 [INFO][63] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-10-26 13:59:20.632 [INFO][63] int_dataplane.go 212: Creating internal dataplane driver. config=intdataplane.Config{IPv6Enabled:true, RuleRendererOverride:rules.RuleRenderer(nil), IPIPMTU:1440, IgnoreLooseRPF:false, MaxIPSetSize:1048576, IPSetsRefreshInterval:10000000000, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckInterval:1000000000, IptablesInsertMode:"insert", IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeout:0, IptablesLockProbeInterval:50000000, NetlinkTimeout:10000000000, RulesConfig:rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4201b52c0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4201b53b0), 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)(0xc42041ece0), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-10-26 13:59:20.632 [INFO][63] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4201b52c0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4201b53b0), 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-10-26 13:59:20.632 [INFO][63] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-10-26 13:59:20.632 [INFO][63] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-10-26 13:59:20.632 [INFO][63] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-10-26 13:59:20.635 [INFO][63] feature_detect.go 108: Updating detected iptables features features=iptables.Features{SNATFullyRandom:true, MASQFullyRandom:true, RestoreSupportsLock:true} iptablesVersion=1.6.2 kernelVersion=4.15.0
2019-10-26 13:59:20.635 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:20.635 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:20.635 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:20.637 [INFO][63] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:20.637 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:20.637 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:20.639 [INFO][63] int_dataplane.go 424: Registering to report health.
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.639 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-10-26 13:59:20.640 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-10-26 13:59:20.640 [INFO][63] daemon.go 299: Connect to the dataplane driver.
2019-10-26 13:59:20.640 [INFO][63] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4201da280), (*watchersyncer.watcherCache)(0xc4201da300), (*watchersyncer.watcherCache)(0xc4201da580), (*watchersyncer.watcherCache)(0xc4201da600), (*watchersyncer.watcherCache)(0xc4201da680), (*watchersyncer.watcherCache)(0xc4201da700), (*watchersyncer.watcherCache)(0xc4201da780), (*watchersyncer.watcherCache)(0xc4201da800), (*watchersyncer.watcherCache)(0xc4201da880), (*watchersyncer.watcherCache)(0xc4201da900)}, results:(chan interface {})(0xc4201ac720), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42000c150), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-10-26 13:59:20.640 [INFO][63] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp002
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 981: Started internal status report thread
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 983: Process status reports disabled
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-10-26 13:59:20.640 [INFO][63] iface_monitor.go 88: Interface monitoring thread started.
2019-10-26 13:59:20.640 [INFO][63] iface_monitor.go 95: Subscribed to netlink updates.
2019-10-26 13:59:20.640 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:20.640 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:20.640 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-10-26 13:59:20.640 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"::1":set.empty{}, "127.0.0.1":set.empty{}} ifaceName="lo"
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-10-26 13:59:20.643 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:20.643 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe0e:d0e":set.empty{}} ifaceName="ens3"
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}} ifaceName="ens4"
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}} ifaceName="ens5"
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:20.644 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:20.644 [INFO][63] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:20.645 [INFO][63] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:20.645 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-10-26 13:59:20.645 [INFO][63] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:20.645 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-10-26 13:59:20.645 [INFO][63] daemon.go 439: Starting the datastore Syncer
2019-10-26 13:59:20.645 [INFO][63] watchersyncer.go 89: Start called
2019-10-26 13:59:20.645 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:20.645 [INFO][63] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-10-26 13:59:20.645 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}, "172.16.10.56":set.empty{}} ifaceName="br-mgmt"
2019-10-26 13:59:20.645 [INFO][63] daemon.go 454: Started the processing graph
2019-10-26 13:59:20.645 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-10-26 13:59:20.645 [INFO][63] daemon.go 813: Reading from dataplane driver pipe...
2019-10-26 13:59:20.646 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}} ifaceName="ens5.1000"
2019-10-26 13:59:20.646 [INFO][63] async_calc_graph.go 134: AsyncCalcGraph running
2019-10-26 13:59:20.646 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.645 [INFO][63] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-10-26 13:59:20.646 [INFO][63] watchersyncer.go 147: Starting main event processing loop
2019-10-26 13:59:20.646 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.646 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe0e:d0e":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe0e:d0e":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.646 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe0e:d0e":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.646 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}}}
2019-10-26 13:59:20.646 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.647 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}}}
2019-10-26 13:59:20.647 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.647 [INFO][63] daemon.go 546: No driver process to monitor
2019-10-26 13:59:20.647 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.647 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.647 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.647 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.647 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.647 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:20.648 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:20.648 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.648 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe5c:910a":set.empty{}}}
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fe5c:910a":set.empty{}}}
2019-10-26 13:59:20.648 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe5c:910a":set.empty{}, "172.16.10.56":set.empty{}}}
2019-10-26 13:59:20.648 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.648 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.648 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.648 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe37:2a2":set.empty{}}}
2019-10-26 13:59:20.649 [INFO][63] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:20.649 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-10-26 13:59:20.649 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-10-26 13:59:20.649 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-10-26 13:59:20.649 [INFO][63] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"77e3fde152bc47f88c962d00f5907118" > config:<key:"ClusterType" value:"k8s,bgp" > config:<key:"DefaultEndpointToHostAction" value:"Return" > config:<key:"EtcdCaFile" value:"/var/lib/etcd/ca.pem" > config:<key:"EtcdCertFile" value:"/var/lib/etcd/etcd-client.crt" > config:<key:"EtcdEndpoints" value:"https://172.16.10.36:4001" > config:<key:"EtcdKeyFile" value:"/var/lib/etcd/etcd-client.key" > config:<key:"FelixHostname" value:"cmp002" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-10-26 13:59:20.649 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 127: Sending status update Status=resync
2019-10-26 13:59:20.650 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.650 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-10-26 13:59:20.650 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-10-26 13:59:20.650 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.650 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.651 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-10-26 13:59:20.652 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-10-26 13:59:20.652 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.652 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.652 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-10-26 13:59:20.652 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-10-26 13:59:20.652 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-10-26 13:59:20.652 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-10-26 13:59:20.652 [INFO][63] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-10-26 13:59:20.652 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.652 [INFO][63] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp002,name=DefaultEndpointToHostAction) Return 8 0s} 1}
2019-10-26 13:59:20.653 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.653 [INFO][63] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:20.653 [INFO][63] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-10-26 13:59:20.653 [INFO][63] watchersyncer.go 127: Sending status update Status=in-sync
2019-10-26 13:59:20.653 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 77e3fde152bc47f88c962d00f5907118 6 0s} 1}
2019-10-26 13:59:20.653 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-10-26 13:59:20.653 [INFO][63] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-10-26 13:59:20.653 [INFO][63] config_batcher.go 102: Datamodel in sync, flushing config update
2019-10-26 13:59:20.653 [INFO][63] config_batcher.go 112: Sending config update global: map[ReportingIntervalSecs:0 ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info], host: map[DefaultEndpointToHostAction:Return].
2019-10-26 13:59:20.654 [INFO][63] async_calc_graph.go 160: First time we've been in sync
2019-10-26 13:59:20.654 [INFO][63] event_sequencer.go 210: Possible config update. global=map[string]string{"ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-10-26 13:59:20.654 [INFO][63] config_params.go 217: Merging in config from datastore (global): map[CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp]
2019-10-26 13:59:20.654 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:20.654 [INFO][63] usagerep.go 83: Waiting before first check-in delay=5m0.833s
2019-10-26 13:59:20.654 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:20.654 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:20.654 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:20.655 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:20.655 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:20.656 [INFO][63] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-10-26 13:59:20.656 [INFO][63] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:20.656 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:20.657 [INFO][63] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:20.657 [INFO][63] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:20.659 [INFO][63] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:20.659 [INFO][63] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:20.660 [INFO][63] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-10-26 13:59:20.660 [INFO][63] daemon.go 892: Datastore now in sync.
2019-10-26 13:59:20.660 [INFO][63] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"192.168.0.0-16" pool:<cidr:"192.168.0.0/16" masquerade:true > 
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fd92:48c:bc74::-48" pool:<cidr:"fd92:48c:bc74::/48" > 
2019-10-26 13:59:20.660 [INFO][63] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-10-26 13:59:20.661 [INFO][63] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=163.872411ms
2019-10-26 13:59:20.661 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.661 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.661 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.662 [INFO][63] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-10-26 13:59:20.662 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-10-26 13:59:20.662 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:20.662 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:20.662 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:20.662 [INFO][63] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:20.675 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=12.771516ms
2019-10-26 13:59:20.675 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:20.675 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-10-26 13:59:20.675 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-10-26 13:59:20.676 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=13.06ms
2019-10-26 13:59:20.679 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-10-26 13:59:20.679 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-10-26 13:59:20.679 [INFO][63] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:20.809 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:20.811 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:20.813 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:20.815 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:20.817 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:20.819 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:20.823 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:20.828 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:21.321 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=660.856813
2019-10-26 13:59:21.322 [INFO][63] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.824893914
2019-10-26 13:59:22.444 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:22.444 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:22.445 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:22.446 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:22.447 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:22.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:22.450 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:22.452 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:22.453 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:22.456 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:22.457 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=13.596069
2019-10-26 13:59:22.944 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:22.944 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:22.946 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:22.948 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.552277
2019-10-26 13:59:22.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:22.950 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:22.952 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:22.953 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1400550000000003
2019-10-26 13:59:23.127 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.128 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:23.129 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:23.130 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6686259999999997
2019-10-26 13:59:23.271 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.271 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:23.273 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:23.275 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9666040000000002
2019-10-26 13:59:23.275 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.276 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:23.276 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:23.278 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.294452
2019-10-26 13:59:23.279 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.279 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:23.279 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:23.281 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2250080000000003
2019-10-26 13:59:23.317 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.317 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:23.318 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:23.321 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.79551
2019-10-26 13:59:23.326 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.326 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:23.327 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:23.329 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.066002
2019-10-26 13:59:24.933 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.934 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:24.935 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:24.937 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1691990000000003
2019-10-26 13:59:24.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.950 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:24.951 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:24.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.939946
2019-10-26 13:59:25.126 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.126 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:25.127 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:25.129 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.324634
2019-10-26 13:59:25.271 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.271 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:25.272 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:25.273 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.573377
2019-10-26 13:59:25.274 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.275 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:25.276 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:25.278 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8513200000000003
2019-10-26 13:59:25.280 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.280 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:25.281 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:25.282 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5933200000000003
2019-10-26 13:59:25.317 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.317 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:25.318 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:25.321 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.994595
2019-10-26 13:59:25.325 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.326 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:25.327 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:25.328 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.518747
2019-10-26 13:59:28.933 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:28.934 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:28.936 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:28.937 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.374573
2019-10-26 13:59:28.951 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:28.951 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:28.952 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:28.953 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.31954
2019-10-26 13:59:29.127 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.127 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:29.129 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:29.131 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.311189
2019-10-26 13:59:29.272 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.273 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:29.273 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:29.274 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:29.275 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:29.277 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.075265
2019-10-26 13:59:29.280 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.280 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:29.281 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:29.283 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.63117
2019-10-26 13:59:29.317 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.317 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:29.318 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:29.320 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.587259
2019-10-26 13:59:29.324 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.324 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:29.325 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:29.327 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6338389999999996
2019-10-26 13:59:31.285 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:31.286 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:31.286 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:31.286 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:31.286 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:31.288 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.379643ms
2019-10-26 13:59:31.289 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.68201ms
2019-10-26 13:59:31.289 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.280551
2019-10-26 13:59:36.931 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:36.931 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:36.932 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:36.934 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.251925
2019-10-26 13:59:36.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:36.950 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:36.951 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:36.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.287227
2019-10-26 13:59:37.127 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.127 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:37.128 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:37.130 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.610276
2019-10-26 13:59:37.272 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.272 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:37.272 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:37.273 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:37.275 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:37.279 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.849667
2019-10-26 13:59:37.283 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.283 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:37.284 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:37.286 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.27161
2019-10-26 13:59:37.318 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.318 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:37.319 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:37.320 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.53265
2019-10-26 13:59:37.324 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.324 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:37.325 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:37.327 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6581080000000004
2019-10-26 13:59:41.717 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:41.718 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:41.718 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:41.718 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:41.718 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:41.720 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.85498ms
2019-10-26 13:59:41.720 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.887531ms
2019-10-26 13:59:41.721 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.354969
2019-10-26 13:59:52.499 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:52.499 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:52.499 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:52.499 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:52.499 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:52.502 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.591458ms
2019-10-26 13:59:52.502 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.624708ms
2019-10-26 13:59:52.502 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.475063
2019-10-26 13:59:52.931 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:52.931 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:52.933 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:52.936 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.16116
2019-10-26 13:59:52.951 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:52.952 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:52.956 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:52.958 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.173214
2019-10-26 13:59:53.130 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.131 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:53.132 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:53.135 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.451969
2019-10-26 13:59:53.273 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.273 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:53.273 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:53.275 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:53.277 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:53.280 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-10-26 13:59:53.280 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c"} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", ""} ipVersion=0x4 table="filter"
2019-10-26 13:59:53.283 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.938377
2019-10-26 13:59:53.286 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.286 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:53.287 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:53.288 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.125276
2019-10-26 13:59:53.317 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.317 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:53.320 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:53.323 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-10-26 13:59:53.325 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.148458000000002
2019-10-26 13:59:53.330 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.330 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:53.332 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:53.335 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.502755
2019-10-26 13:59:54.287 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.288 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:54.290 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:54.292 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.4027199999999995
2019-10-26 13:59:54.329 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.330 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:54.332 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:54.335 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.729286999999999
2019-10-26 13:59:55.288 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.288 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:55.291 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:55.294 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.757377
2019-10-26 13:59:55.330 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.331 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:55.333 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:55.336 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.2674460000000005
2019-10-26 13:59:57.288 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:57.288 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:57.290 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:57.294 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.461131999999999
2019-10-26 13:59:57.330 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:57.331 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:57.333 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:57.336 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.099083
2019-10-26 14:00:01.288 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:01.288 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:01.290 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:01.292 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.127691
2019-10-26 14:00:01.329 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:01.329 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:01.331 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:01.333 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.567851
2019-10-26 14:00:02.511 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:02.512 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:02.512 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:02.512 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:02.512 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:02.514 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.090877ms
2019-10-26 14:00:02.514 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.021595ms
2019-10-26 14:00:02.515 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.922192
2019-10-26 14:00:09.283 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:09.283 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:09.284 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:09.285 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4214610000000003
2019-10-26 14:00:09.327 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:09.327 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:09.328 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:09.331 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.14902
2019-10-26 14:00:13.040 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:13.040 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:13.040 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:13.040 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:13.040 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:13.042 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.587045ms
2019-10-26 14:00:13.043 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.664678ms
2019-10-26 14:00:13.043 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1434879999999996
2019-10-26 14:00:23.453 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:23.454 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:23.454 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:23.454 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:23.454 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:23.456 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.291802ms
2019-10-26 14:00:23.457 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.231557ms
2019-10-26 14:00:23.457 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.842822
2019-10-26 14:00:24.931 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:24.931 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:00:24.933 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:24.934 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.865552
2019-10-26 14:00:24.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:24.950 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:00:24.951 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:00:24.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.948993
2019-10-26 14:00:25.126 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.126 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:00:25.127 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:00:25.129 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.33411
2019-10-26 14:00:25.271 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.271 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:00:25.272 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:00:25.273 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.515478
2019-10-26 14:00:25.279 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.279 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:00:25.281 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:00:25.283 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.391737
2019-10-26 14:00:25.287 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.287 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:25.289 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:25.291 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7957899999999998
2019-10-26 14:00:25.325 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.325 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:25.325 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:00:25.327 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:25.328 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:00:25.331 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.373959
2019-10-26 14:00:33.579 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:33.579 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:33.579 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:33.579 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:33.580 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:33.584 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.637788ms
2019-10-26 14:00:33.585 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=5.17207ms
2019-10-26 14:00:33.585 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.44531
2019-10-26 14:00:44.057 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:44.057 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:44.057 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:44.057 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:44.057 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:44.058 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.237398ms
2019-10-26 14:00:44.058 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.300496ms
2019-10-26 14:00:44.059 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.6039809999999999
2019-10-26 14:00:53.230 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:53.230 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:00:53.230 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:00:53.231 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.0995169999999999
2019-10-26 14:00:54.981 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:54.981 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:54.981 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:54.981 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:54.981 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:54.984 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.56304ms
2019-10-26 14:00:54.984 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.963965ms
2019-10-26 14:00:54.985 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.3388609999999996
2019-10-26 14:00:57.283 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:57.283 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:57.285 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:57.287 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:57.287 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c", ""} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", "", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:57.287 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:57.289 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.7696700000000005
2019-10-26 14:00:57.330 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:57.331 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:57.332 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:57.335 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-10-26 14:00:57.335 [WARNING][63] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-10-26 14:00:57.338 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.203269
2019-10-26 14:00:58.296 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.296 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:58.298 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:58.302 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.962505
2019-10-26 14:00:58.344 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.344 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:58.345 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:58.346 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.570922
2019-10-26 14:00:59.291 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.292 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:59.294 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:59.297 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.058826
2019-10-26 14:00:59.343 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.343 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:59.345 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:59.349 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.264011
2019-10-26 14:01:00.196 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.197 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{}}
2019-10-26 14:01:00.197 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{}}
2019-10-26 14:01:00.197 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{}}
2019-10-26 14:01:00.197 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.197 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.13105
2019-10-26 14:01:00.197 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="cali78b77b6ae44" state="up"
2019-10-26 14:01:00.198 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali78b77b6ae44", State:"up"}
2019-10-26 14:01:00.198 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.198 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.198 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.198 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.198 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.205 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.205 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.64/32 ifaceName="cali78b77b6ae44" ipVersion=0x4
2019-10-26 14:01:00.206 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali78b77b6ae44" ipVersion=0x4
2019-10-26 14:01:00.206 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.955621
2019-10-26 14:01:00.206 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.206 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.206 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali78b77b6ae44", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.206 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.206 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.64/32 ifaceName="cali78b77b6ae44" ipVersion=0x4
2019-10-26 14:01:00.206 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali78b77b6ae44" ipVersion=0x4
2019-10-26 14:01:00.206 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.25279
2019-10-26 14:01:00.208 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-zndnv, name=eth0)
2019-10-26 14:01:00.209 [INFO][63] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"allow" rule_id:"YLdFWiauLlZiqqnX" > outbound_rules:<action:"allow" rule_id:"s12JEevpe1A9nAkJ" > > 
2019-10-26 14:01:00.209 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.209 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.210 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-zndnv" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali78b77b6ae44" mac:"da:29:4d:4c:d0:30" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-10-26 14:01:00.210 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.210 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali78b77b6ae44" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali78b77b6ae44" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.210 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.210 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.210 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.211 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.211 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.211 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.211 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali78b77b6ae44" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.211 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali78b77b6ae44" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.211 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.211 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.211 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.211 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:00.211 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.211 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:00.214 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:00.215 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:00.268 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:00.269 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"} status="up"
2019-10-26 14:01:00.269 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=59.056472
2019-10-26 14:01:00.424 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali83342c7add6"
2019-10-26 14:01:00.425 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{}}
2019-10-26 14:01:00.425 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{}}
2019-10-26 14:01:00.425 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{}}
2019-10-26 14:01:00.425 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.425 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.14365299999999998
2019-10-26 14:01:00.426 [INFO][63] int_dataplane.go 471: Linux interface state changed. ifaceName="cali83342c7add6" state="up"
2019-10-26 14:01:00.426 [INFO][63] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali83342c7add6", State:"up"}
2019-10-26 14:01:00.426 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.426 [INFO][63] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali83342c7add6"
2019-10-26 14:01:00.426 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.426 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.426 [INFO][63] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.426 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.427 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="cali83342c7add6" ipVersion=0x4
2019-10-26 14:01:00.427 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali83342c7add6" ipVersion=0x4
2019-10-26 14:01:00.427 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.99733
2019-10-26 14:01:00.427 [INFO][63] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.427 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.427 [INFO][63] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali83342c7add6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.427 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.427 [INFO][63] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="cali83342c7add6" ipVersion=0x4
2019-10-26 14:01:00.427 [INFO][63] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali83342c7add6" ipVersion=0x4
2019-10-26 14:01:00.428 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.344639
2019-10-26 14:01:00.431 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-mvmhn, name=eth0)
2019-10-26 14:01:00.431 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-mvmhn" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali83342c7add6" mac:"9e:6f:41:bd:fd:d2" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-10-26 14:01:00.431 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.431 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.432 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali83342c7add6" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.432 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:00.432 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali83342c7add6" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.432 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.432 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.432 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.432 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.432 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.432 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.432 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.433 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali83342c7add6" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.433 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:00.433 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali83342c7add6" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.433 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.433 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.433 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.433 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:00.433 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.433 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:00.438 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:00.439 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:00.443 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:00.443 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"} status="up"
2019-10-26 14:01:00.443 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.534911
2019-10-26 14:01:01.345 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.346 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:01.347 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:01.350 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.216018999999999
2019-10-26 14:01:01.446 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.446 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:01.446 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:01.447 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:01.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:01.451 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.252813000000001
2019-10-26 14:01:01.536 [INFO][63] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-10-26 14:01:01.952 [INFO][63] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-10-26 14:01:02.447 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:02.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:02.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:02.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:02.450 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:02.453 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.293712
2019-10-26 14:01:04.448 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:04.448 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:04.448 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:04.450 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:04.451 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:04.456 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.662119000000001
2019-10-26 14:01:05.057 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:05.057 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:05.057 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:05.057 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:05.057 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:05.059 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.372595ms
2019-10-26 14:01:05.059 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.870702ms
2019-10-26 14:01:05.060 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.786126
2019-10-26 14:01:05.338 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:05.339 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:05.340 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:05.344 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.867808
2019-10-26 14:01:08.110 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-zndnv, name=eth0)
2019-10-26 14:01:08.110 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-zndnv" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali78b77b6ae44" mac:"da:29:4d:4c:d0:30" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-10-26 14:01:08.111 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.111 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.111 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali78b77b6ae44" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.111 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:08.111 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali78b77b6ae44" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.111 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.111 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:08.111 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.111 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.111 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.112 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali78b77b6ae44" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.112 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:08.112 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali78b77b6ae44" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.112 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.112 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali78b77b6ae44"
2019-10-26 14:01:08.112 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.112 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"}
2019-10-26 14:01:08.116 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.118 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.121 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:08.121 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-zndnv", EndpointId:"eth0"} status="up"
2019-10-26 14:01:08.121 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.499894
2019-10-26 14:01:08.217 [INFO][63] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-mvmhn, name=eth0)
2019-10-26 14:01:08.217 [INFO][63] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-mvmhn" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali83342c7add6" mac:"9e:6f:41:bd:fd:d2" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-10-26 14:01:08.217 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.217 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali83342c7add6" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.218 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:08.218 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali83342c7add6" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-tw-cali83342c7add6" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.218 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:08.218 [INFO][63] table.go 417: Queueing update of chain. chainName="cali-fw-cali83342c7add6" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali83342c7add6"
2019-10-26 14:01:08.218 [INFO][63] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][63] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"}
2019-10-26 14:01:08.221 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.223 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.225 [INFO][63] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-10-26 14:01:08.225 [INFO][63] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-mvmhn", EndpointId:"eth0"} status="up"
2019-10-26 14:01:08.225 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.8638449999999995
2019-10-26 14:01:08.448 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.448 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:08.448 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:08.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.450 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.453 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.724921
2019-10-26 14:01:13.344 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:13.344 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:13.346 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:13.349 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.321575
2019-10-26 14:01:15.268 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:15.268 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:15.268 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:15.268 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:15.268 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:15.284 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=15.861714ms
2019-10-26 14:01:15.284 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=15.862635ms
2019-10-26 14:01:15.284 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.176778
2019-10-26 14:01:16.442 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:16.442 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:16.447 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:16.450 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.6687780000000005
2019-10-26 14:01:16.450 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:16.451 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:16.452 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:16.455 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.988734
2019-10-26 14:01:26.252 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:26.252 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:26.253 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:26.253 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:26.253 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:26.256 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.349109ms
2019-10-26 14:01:26.257 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.805858ms
2019-10-26 14:01:26.257 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.434583
2019-10-26 14:01:28.947 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:28.947 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:01:28.949 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:01:28.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.705596
2019-10-26 14:01:29.129 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.129 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:01:29.131 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:01:29.135 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.959357
2019-10-26 14:01:29.274 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.274 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:01:29.276 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:01:29.279 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.566758
2019-10-26 14:01:29.281 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.281 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:01:29.283 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:01:29.286 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.7489419999999996
2019-10-26 14:01:29.326 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.326 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:01:29.328 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:01:29.332 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.841316
2019-10-26 14:01:29.344 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.344 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:29.345 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:29.348 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.487789
2019-10-26 14:01:32.446 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:32.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:32.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:32.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:32.451 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:32.458 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.538043
2019-10-26 14:01:36.919 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:36.919 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:36.919 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:36.919 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:36.919 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:36.922 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.168898ms
2019-10-26 14:01:36.922 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.376813ms
2019-10-26 14:01:36.922 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0252109999999997
2019-10-26 14:01:47.357 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:47.357 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:47.357 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:47.357 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:47.357 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:47.359 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.707102ms
2019-10-26 14:01:47.359 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.970135ms
2019-10-26 14:01:47.360 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.392178
2019-10-26 14:01:57.760 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:57.760 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:57.760 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:57.760 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:57.760 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:57.762 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.000104ms
2019-10-26 14:01:57.763 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.179138ms
2019-10-26 14:01:57.763 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.864022
2019-10-26 14:02:01.338 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:01.338 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:02:01.342 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:02:01.345 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.0361579999999995
2019-10-26 14:02:04.449 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:04.449 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:02:04.449 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:02:04.451 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:02:04.453 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:02:04.457 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.322651
2019-10-26 14:02:08.120 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:08.121 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:08.121 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:08.121 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:08.121 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:08.123 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.086959ms
2019-10-26 14:02:08.124 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.509812ms
2019-10-26 14:02:08.124 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.526611
2019-10-26 14:02:18.392 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:18.392 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:18.392 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:18.392 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:18.393 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:18.394 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.124083ms
2019-10-26 14:02:18.394 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.445348ms
2019-10-26 14:02:18.394 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.759379
2019-10-26 14:02:28.737 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:28.737 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:28.737 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:28.737 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:28.737 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:28.738 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.126918ms
2019-10-26 14:02:28.738 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.212948ms
2019-10-26 14:02:28.738 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.499736
2019-10-26 14:02:31.867 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:31.867 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:02:31.867 [INFO][63] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:02:31.869 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4803170000000003
2019-10-26 14:02:39.711 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:39.711 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:39.711 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:39.711 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:39.711 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:39.713 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.862227ms
2019-10-26 14:02:39.713 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.682102ms
2019-10-26 14:02:39.713 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.194687
2019-10-26 14:02:50.390 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:50.390 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:50.390 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:50.390 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:50.391 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:50.392 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.671226ms
2019-10-26 14:02:50.393 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.826118ms
2019-10-26 14:02:50.393 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.758111
2019-10-26 14:02:58.950 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:58.950 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-10-26 14:02:58.951 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:02:58.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.162658
2019-10-26 14:02:59.134 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.134 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-10-26 14:02:59.135 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:02:59.136 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.457316
2019-10-26 14:02:59.279 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.279 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-10-26 14:02:59.283 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:02:59.286 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.897175
2019-10-26 14:02:59.290 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.290 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-10-26 14:02:59.291 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:02:59.293 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.459886
2019-10-26 14:02:59.331 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.331 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-10-26 14:02:59.333 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:02:59.335 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8201530000000004
2019-10-26 14:03:01.160 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:01.160 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:01.160 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:01.160 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:01.161 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:01.164 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.641051ms
2019-10-26 14:03:01.165 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.087686ms
2019-10-26 14:03:01.165 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.513479
2019-10-26 14:03:05.338 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:05.338 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:03:05.340 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:03:05.343 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.101763
2019-10-26 14:03:08.447 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:08.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:03:08.447 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:03:08.448 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:03:08.449 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:03:08.451 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.413899
2019-10-26 14:03:11.348 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:11.348 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:11.348 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:11.348 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:11.348 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:11.349 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.105538ms
2019-10-26 14:03:11.350 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.578405ms
2019-10-26 14:03:11.350 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.88278
2019-10-26 14:03:21.686 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:21.686 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:21.686 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:21.686 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:21.686 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:21.689 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.335602ms
2019-10-26 14:03:21.689 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.916221ms
2019-10-26 14:03:21.690 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.382632
2019-10-26 14:03:32.270 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:32.271 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:32.271 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:32.271 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:32.271 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:32.272 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.139916ms
2019-10-26 14:03:32.272 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.251559ms
2019-10-26 14:03:32.272 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.524175
2019-10-26 14:03:36.947 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:36.947 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:03:36.949 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:03:36.952 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.895408000000001
2019-10-26 14:03:37.129 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.129 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:03:37.131 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:03:37.134 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.653338
2019-10-26 14:03:37.273 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.273 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:03:37.275 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:03:37.278 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.053038
2019-10-26 14:03:37.281 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.281 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:03:37.282 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:03:37.284 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.881812
2019-10-26 14:03:37.324 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.324 [INFO][63] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:03:37.326 [INFO][63] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:03:37.330 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.196701
2019-10-26 14:03:43.124 [INFO][63] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:43.124 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:43.124 [INFO][63] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:43.124 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:43.124 [INFO][63] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:43.126 [INFO][63] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.012747ms
2019-10-26 14:03:43.127 [INFO][63] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.456106ms
2019-10-26 14:03:43.127 [INFO][63] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.840689
