2019-10-26 13:59:21.557 [INFO][70] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=8 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"ctl01", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"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{0x4:map[string]string{"etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"ctl01", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key"}, 0x3:map[string]string{"LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None"}, 0x1:map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "EtcdEndpoints":"https://172.16.10.36:4001", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None", "ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdCaFile":"/var/lib/etcd/ca.pem", "FelixHostname":"ctl01", "MetadataAddr":"None", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "DefaultEndpointToHostAction":"Return"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-10-26 13:59:21.558 [INFO][70] driver.go 43: Using internal (linux) dataplane driver.
2019-10-26 13:59:21.558 [INFO][70] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-10-26 13:59:21.558 [INFO][70] 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)(0xc42050e500), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc42050e5f0), 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)(0xc42014e5e0), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-10-26 13:59:21.558 [INFO][70] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc42050e500), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc42050e5f0), 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:21.558 [INFO][70] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-10-26 13:59:21.558 [INFO][70] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-10-26 13:59:21.558 [INFO][70] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-10-26 13:59:21.561 [INFO][70] 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:21.562 [INFO][70] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:21.562 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.562 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.562 [INFO][70] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:21.562 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.562 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.562 [INFO][70] int_dataplane.go 424: Registering to report health.
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.564 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.565 [INFO][70] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.566 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.566 [INFO][70] daemon.go 299: Connect to the dataplane driver.
2019-10-26 13:59:21.566 [INFO][70] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-10-26 13:59:21.566 [INFO][70] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4201c2080), (*watchersyncer.watcherCache)(0xc4201c2100), (*watchersyncer.watcherCache)(0xc4201c2180), (*watchersyncer.watcherCache)(0xc4201c2200), (*watchersyncer.watcherCache)(0xc4201c2280), (*watchersyncer.watcherCache)(0xc4201c2300), (*watchersyncer.watcherCache)(0xc4201c2580), (*watchersyncer.watcherCache)(0xc4201c2600), (*watchersyncer.watcherCache)(0xc4201c2680), (*watchersyncer.watcherCache)(0xc4201c2700)}, results:(chan interface {})(0xc4207fc540), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42055a070), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-10-26 13:59:21.566 [INFO][70] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-10-26 13:59:21.567 [INFO][70] calc_graph.go 96: Creating calculation graph, filtered to hostname ctl01
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 981: Started internal status report thread
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 983: Process status reports disabled
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:21.567 [INFO][70] iface_monitor.go 88: Interface monitoring thread started.
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] iface_monitor.go 95: Subscribed to netlink updates.
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fed1:44f2":set.empty{}, "192.168.11.21":set.empty{}} ifaceName="ens3"
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-10-26 13:59:21.567 [INFO][70] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.567 [INFO][70] daemon.go 439: Starting the datastore Syncer
2019-10-26 13:59:21.567 [INFO][70] watchersyncer.go 89: Start called
2019-10-26 13:59:21.567 [INFO][70] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fecc:bfd7":set.empty{}} ifaceName="ens4"
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-10-26 13:59:21.567 [INFO][70] daemon.go 454: Started the processing graph
2019-10-26 13:59:21.567 [INFO][70] daemon.go 813: Reading from dataplane driver pipe...
2019-10-26 13:59:21.567 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}} ifaceName="ens5"
2019-10-26 13:59:21.568 [INFO][70] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-10-26 13:59:21.568 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-10-26 13:59:21.568 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-10-26 13:59:21.568 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fecc:bfd7":set.empty{}} ifaceName="br-mgmt"
2019-10-26 13:59:21.568 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-10-26 13:59:21.569 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}} ifaceName="ens5.1000"
2019-10-26 13:59:21.568 [INFO][70] watchersyncer.go 147: Starting main event processing loop
2019-10-26 13:59:21.570 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-10-26 13:59:21.570 [INFO][70] async_calc_graph.go 134: AsyncCalcGraph running
2019-10-26 13:59:21.570 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-10-26 13:59:21.570 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-10-26 13:59:21.570 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-10-26 13:59:21.570 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-10-26 13:59:21.571 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-10-26 13:59:21.571 [INFO][70] 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:"ctl01" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-10-26 13:59:21.571 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"::1":set.empty{}, "127.0.0.1":set.empty{}}}
2019-10-26 13:59:21.571 [INFO][70] 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:21.571 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.571 [INFO][70] 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:21.571 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.572 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fed1:44f2":set.empty{}, "192.168.11.21":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fed1:44f2":set.empty{}, "192.168.11.21":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.572 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fed1:44f2":set.empty{}, "192.168.11.21":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.572 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.572 [INFO][70] daemon.go 546: No driver process to monitor
2019-10-26 13:59:21.572 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.572 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.572 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.573 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.573 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.573 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.573 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.573 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.573 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.573 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.573 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.573 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.573 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.574 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-10-26 13:59:21.574 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fecc:bfd7":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.574 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.574 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-10-26 13:59:21.574 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fedd:4a72":set.empty{}}}
2019-10-26 13:59:21.574 [INFO][70] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.574 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-10-26 13:59:21.574 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-10-26 13:59:21.575 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-10-26 13:59:21.575 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-10-26 13:59:21.575 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-10-26 13:59:21.575 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-10-26 13:59:21.575 [INFO][70] watchersyncer.go 127: Sending status update Status=resync
2019-10-26 13:59:21.575 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.575 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-10-26 13:59:21.575 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] watchersyncer.go 127: Sending status update Status=in-sync
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 61: Host config update for this host: {{HostConfig(node=ctl01,name=DefaultEndpointToHostAction) Return 12 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 77e3fde152bc47f88c962d00f5907118 6 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 102: Datamodel in sync, flushing config update
2019-10-26 13:59:21.576 [INFO][70] config_batcher.go 112: Sending config update global: map[ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[DefaultEndpointToHostAction:Return].
2019-10-26 13:59:21.577 [INFO][70] async_calc_graph.go 160: First time we've been in sync
2019-10-26 13:59:21.577 [INFO][70] event_sequencer.go 210: Possible config update. global=map[string]string{"LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-10-26 13:59:21.577 [INFO][70] config_params.go 217: Merging in config from datastore (global): map[ReportingIntervalSecs:0 ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info]
2019-10-26 13:59:21.577 [INFO][70] usagerep.go 83: Waiting before first check-in delay=5m0.624s
2019-10-26 13:59:21.577 [INFO][70] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-10-26 13:59:21.577 [INFO][70] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:21.578 [INFO][70] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:21.579 [INFO][70] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.580 [INFO][70] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-10-26 13:59:21.580 [INFO][70] daemon.go 892: Datastore now in sync.
2019-10-26 13:59:21.580 [INFO][70] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-10-26 13:59:21.580 [INFO][70] 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:21.580 [INFO][70] 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:21.580 [INFO][70] 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:21.580 [INFO][70] 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:21.581 [INFO][70] 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:21.581 [INFO][70] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-10-26 13:59:21.581 [INFO][70] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=161.986161ms
2019-10-26 13:59:21.581 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.581 [INFO][70] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-10-26 13:59:21.581 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.582 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.582 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.582 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.584 [INFO][70] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-10-26 13:59:21.584 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.584 [INFO][70] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:21.585 [INFO][70] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:21.585 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:21.585 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:21.612 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=26.547812ms
2019-10-26 13:59:21.613 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:21.613 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-10-26 13:59:21.613 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-10-26 13:59:21.613 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=28.113499ms
2019-10-26 13:59:21.614 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-10-26 13:59:21.614 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-10-26 13:59:21.615 [INFO][70] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:21.766 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:21.768 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:21.771 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:21.772 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:21.773 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:21.775 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.777 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:21.779 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:22.337 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=756.025671
2019-10-26 13:59:22.337 [INFO][70] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.918229612
2019-10-26 13:59:23.464 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:23.464 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:23.465 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:23.465 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:23.466 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:23.466 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:23.468 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:23.469 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:23.471 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:23.474 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:23.475 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:23.477 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:23.483 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=18.752131
2019-10-26 13:59:23.911 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.911 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:23.911 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:23.913 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:23.916 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:23.918 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.831028
2019-10-26 13:59:24.116 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.116 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:24.118 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:24.119 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4814920000000003
2019-10-26 13:59:24.136 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.137 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:24.139 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:24.140 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.790368
2019-10-26 13:59:24.142 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.142 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:24.147 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:24.150 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.631729
2019-10-26 13:59:24.333 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.333 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:24.334 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:24.336 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0125159999999997
2019-10-26 13:59:24.340 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:24.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:24.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:24.342 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:24.343 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.198134
2019-10-26 13:59:25.895 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.896 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:25.897 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:25.901 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.363608
2019-10-26 13:59:25.912 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.912 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:25.913 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:25.914 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.52268
2019-10-26 13:59:26.112 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.112 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:26.113 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:26.115 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1570970000000003
2019-10-26 13:59:26.136 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.136 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:26.137 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:26.139 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.296447
2019-10-26 13:59:26.140 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.141 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:26.141 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:26.144 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.454289
2019-10-26 13:59:26.328 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.329 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:26.330 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:26.331 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.32557
2019-10-26 13:59:26.339 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.339 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:26.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:26.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:26.344 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:26.345 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.922443
2019-10-26 13:59:29.898 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.898 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:29.899 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:29.900 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.73891
2019-10-26 13:59:29.909 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.909 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:29.912 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:29.913 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.601301
2019-10-26 13:59:30.113 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.113 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:30.114 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:30.115 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.618984
2019-10-26 13:59:30.136 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.136 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:30.137 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:30.139 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.975146
2019-10-26 13:59:30.141 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.141 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:30.142 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:30.144 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0991560000000002
2019-10-26 13:59:30.328 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.328 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:30.329 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:30.331 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.601015
2019-10-26 13:59:30.339 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.339 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:30.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:30.340 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:30.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:30.343 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.170315
2019-10-26 13:59:32.166 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:32.166 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:32.167 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:32.167 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:32.167 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:32.169 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.964418ms
2019-10-26 13:59:32.169 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.896035ms
2019-10-26 13:59:32.169 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3670229999999997
2019-10-26 13:59:37.892 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.892 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:37.894 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:37.895 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.947558
2019-10-26 13:59:37.909 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.909 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:37.910 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:37.911 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.932275
2019-10-26 13:59:38.111 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.111 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:38.113 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:38.115 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9816160000000003
2019-10-26 13:59:38.137 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.137 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:38.138 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:38.139 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.872706
2019-10-26 13:59:38.141 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.141 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:38.142 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:38.144 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.461611
2019-10-26 13:59:38.327 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.328 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:38.329 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:38.331 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1680710000000003
2019-10-26 13:59:38.340 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:38.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:38.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:38.342 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:38.344 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.54655
2019-10-26 13:59:43.071 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:43.071 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:43.071 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:43.071 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:43.071 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:43.072 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.030412ms
2019-10-26 13:59:43.072 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.268196ms
2019-10-26 13:59:43.073 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.639915
2019-10-26 13:59:53.561 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.561 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:53.561 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:53.561 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:53.562 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:53.563 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.230009ms
2019-10-26 13:59:53.563 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.426412ms
2019-10-26 13:59:53.564 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.352204
2019-10-26 13:59:53.893 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.893 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:53.894 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:53.896 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.92117
2019-10-26 13:59:53.909 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.909 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:53.910 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:53.911 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2231080000000003
2019-10-26 13:59:54.111 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.111 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:54.112 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:54.114 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.306408
2019-10-26 13:59:54.135 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.136 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:54.137 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:54.139 [WARNING][70] 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:54.141 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.9661979999999994
2019-10-26 13:59:54.144 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.144 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:54.145 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:54.146 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1421769999999998
2019-10-26 13:59:54.327 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.327 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:54.328 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:54.330 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.459462
2019-10-26 13:59:54.339 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:54.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:54.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:54.342 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:54.347 [WARNING][70] 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:54.347 [WARNING][70] 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:54.349 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.594741
2019-10-26 13:59:55.151 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.152 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:55.154 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:55.156 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.83656
2019-10-26 13:59:55.353 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.354 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:55.356 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:55.359 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.634298
2019-10-26 13:59:56.147 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:56.147 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:56.149 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:56.151 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.454574
2019-10-26 13:59:56.352 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:56.353 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:56.354 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:56.357 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.078262
2019-10-26 13:59:58.146 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:58.146 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:58.147 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:58.148 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.492157
2019-10-26 13:59:58.352 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:58.352 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:58.354 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:58.356 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.461493000000001
2019-10-26 14:00:02.146 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:02.146 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:02.148 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:02.151 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.579332
2019-10-26 14:00:02.353 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:02.354 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:02.355 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:02.357 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7137569999999998
2019-10-26 14:00:04.433 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:04.433 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:04.433 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:04.433 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:04.433 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:04.434 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.371466ms
2019-10-26 14:00:04.435 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.075663ms
2019-10-26 14:00:04.436 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8442
2019-10-26 14:00:10.142 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:10.142 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:10.143 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:10.144 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.541721
2019-10-26 14:00:10.352 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:10.352 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:10.353 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:10.357 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.175809
2019-10-26 14:00:14.441 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:14.441 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:14.441 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:14.442 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:14.442 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:14.443 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.567728ms
2019-10-26 14:00:14.444 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.383848ms
2019-10-26 14:00:14.444 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.584275
2019-10-26 14:00:24.916 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:24.916 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:24.916 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:24.916 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:24.916 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:24.918 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.273333ms
2019-10-26 14:00:24.920 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.717976ms
2019-10-26 14:00:24.920 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.016066
2019-10-26 14:00:25.892 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.893 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:00:25.894 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:25.896 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.072114
2019-10-26 14:00:25.910 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.911 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:00:25.912 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:00:25.913 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.023882
2019-10-26 14:00:26.112 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.112 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:00:26.114 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:00:26.116 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.572175
2019-10-26 14:00:26.142 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.142 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:00:26.142 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:26.144 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:00:26.145 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:26.147 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.269305
2019-10-26 14:00:26.330 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.330 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:00:26.331 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:00:26.333 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.853209
2019-10-26 14:00:26.340 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:00:26.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:00:26.343 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.294875
2019-10-26 14:00:26.352 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.353 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:26.353 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:26.355 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.399572
2019-10-26 14:00:35.841 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:35.842 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:35.842 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:35.842 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:35.842 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:35.844 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.064209ms
2019-10-26 14:00:35.844 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.140483ms
2019-10-26 14:00:35.844 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.624522
2019-10-26 14:00:45.918 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:45.918 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:45.918 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:45.918 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:45.918 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:45.920 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.842273ms
2019-10-26 14:00:45.922 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.097957ms
2019-10-26 14:00:45.922 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8893869999999997
2019-10-26 14:00:56.892 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:56.892 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:56.892 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:56.892 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:56.892 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:56.895 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.319156ms
2019-10-26 14:00:56.895 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.500427ms
2019-10-26 14:00:56.895 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0386409999999997
2019-10-26 14:00:58.142 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.142 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:58.143 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:58.144 [WARNING][70] 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:58.145 [WARNING][70] 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:58.146 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.303748
2019-10-26 14:00:58.353 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.354 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:58.355 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:58.358 [WARNING][70] 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:58.358 [WARNING][70] 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:58.358 [WARNING][70] 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:58.359 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.504234
2019-10-26 14:00:58.689 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calibd967d734cf"
2019-10-26 14:00:58.690 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{}}
2019-10-26 14:00:58.691 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{}}
2019-10-26 14:00:58.692 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="calibd967d734cf" state="up"
2019-10-26 14:00:58.692 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{}}
2019-10-26 14:00:58.692 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.694 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calibd967d734cf"
2019-10-26 14:00:58.694 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.148534
2019-10-26 14:00:58.694 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calibd967d734cf", State:"up"}
2019-10-26 14:00:58.694 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.694 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.694 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.695 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.695 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.695 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="calibd967d734cf" ipVersion=0x4
2019-10-26 14:00:58.695 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calibd967d734cf" ipVersion=0x4
2019-10-26 14:00:58.695 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.830442
2019-10-26 14:00:58.695 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:58.695 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:58.695 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calibd967d734cf", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:58.695 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.696 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="calibd967d734cf" ipVersion=0x4
2019-10-26 14:00:58.696 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calibd967d734cf" ipVersion=0x4
2019-10-26 14:00:58.696 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.278644
2019-10-26 14:00:58.698 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-5mrgs, name=eth0)
2019-10-26 14:00:58.698 [WARNING][70] active_rules_calculator.go 326: Profile not known or invalid, generating dummy profile that drops all traffic. profileID="calico-k8s-network"
2019-10-26 14:00:58.698 [INFO][70] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"deny" rule_id:"oj2OqMy9CAebzGBO" > outbound_rules:<action:"deny" rule_id:"Eaor-oJ4HE6fBT4g" > > 
2019-10-26 14:00:58.699 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.699 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:00:58.699 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.699 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.699 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:00:58.699 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.699 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-5mrgs" endpoint_id:"eth0" > endpoint:<state:"active" name:"calibd967d734cf" mac:"62:f8:25:00:45:ed" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-10-26 14:00:58.699 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.699 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.699 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calibd967d734cf" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calibd967d734cf" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.700 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.700 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.700 [INFO][70] 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-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calibd967d734cf" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calibd967d734cf" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.700 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.700 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.700 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:00:58.700 [INFO][70] 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-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.700 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:00:58.703 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:58.704 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:58.711 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:00:58.711 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"} status="up"
2019-10-26 14:00:58.711 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.860769
2019-10-26 14:00:58.711 [INFO][70] 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:00:58.712 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.712 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:00:58.712 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:00:58.712 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.712 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:00:58.712 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:00:58.712 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.717 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:58.718 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:58.723 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.053894000000001
2019-10-26 14:00:59.156 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.156 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:59.158 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:59.162 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.681888000000001
2019-10-26 14:00:59.590 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calib68953dea40"
2019-10-26 14:00:59.590 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{}}
2019-10-26 14:00:59.590 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{}}
2019-10-26 14:00:59.590 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{}}
2019-10-26 14:00:59.590 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.591 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.153291
2019-10-26 14:00:59.591 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="calib68953dea40" state="up"
2019-10-26 14:00:59.592 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calib68953dea40"
2019-10-26 14:00:59.592 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calib68953dea40", State:"up"}
2019-10-26 14:00:59.592 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.592 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calib68953dea40"
2019-10-26 14:00:59.592 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:00:59.593 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calib68953dea40"
2019-10-26 14:00:59.593 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:00:59.593 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.1/32 ifaceName="calib68953dea40" ipVersion=0x4
2019-10-26 14:00:59.593 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calib68953dea40" ipVersion=0x4
2019-10-26 14:00:59.593 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.237787
2019-10-26 14:00:59.593 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.594 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.594 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calib68953dea40", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.594 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.594 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.1/32 ifaceName="calib68953dea40" ipVersion=0x4
2019-10-26 14:00:59.594 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calib68953dea40" ipVersion=0x4
2019-10-26 14:00:59.594 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.444703
2019-10-26 14:00:59.595 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-fkm4q, name=eth0)
2019-10-26 14:00:59.595 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-fkm4q" endpoint_id:"eth0" > endpoint:<state:"active" name:"calib68953dea40" mac:"36:6f:a1:e0:28:25" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-10-26 14:00:59.595 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.595 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.595 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calib68953dea40" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.595 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:00:59.595 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calib68953dea40" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.595 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.595 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.595 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.595 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:00:59.596 [INFO][70] 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-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.596 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.596 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.596 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calib68953dea40" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.596 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:00:59.596 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calib68953dea40" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.596 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.596 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.596 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.596 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:00:59.596 [INFO][70] 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-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.596 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:00:59.601 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:59.603 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:59.657 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:00:59.657 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"} status="up"
2019-10-26 14:00:59.657 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=61.921051
2019-10-26 14:00:59.809 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.809 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{}}
2019-10-26 14:00:59.809 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{}}
2019-10-26 14:00:59.809 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{}}
2019-10-26 14:00:59.809 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.813 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.297895
2019-10-26 14:00:59.813 [INFO][70] int_dataplane.go 471: Linux interface state changed. ifaceName="calie8cee6818cb" state="up"
2019-10-26 14:00:59.814 [INFO][70] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calie8cee6818cb", State:"up"}
2019-10-26 14:00:59.814 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.814 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.814 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.814 [INFO][70] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.814 [INFO][70] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.814 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.814 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.2/32 ifaceName="calie8cee6818cb" ipVersion=0x4
2019-10-26 14:00:59.814 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calie8cee6818cb" ipVersion=0x4
2019-10-26 14:00:59.815 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.677533
2019-10-26 14:00:59.815 [INFO][70] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.815 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.815 [INFO][70] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calie8cee6818cb", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:00:59.815 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.815 [INFO][70] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.2/32 ifaceName="calie8cee6818cb" ipVersion=0x4
2019-10-26 14:00:59.815 [INFO][70] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calie8cee6818cb" ipVersion=0x4
2019-10-26 14:00:59.815 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.28355600000000003
2019-10-26 14:00:59.821 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-r46ls, name=eth0)
2019-10-26 14:00:59.821 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-r46ls" endpoint_id:"eth0" > endpoint:<state:"active" name:"calie8cee6818cb" mac:"d6:cf:6a:81:a5:d9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-10-26 14:00:59.821 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.821 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.821 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calie8cee6818cb" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.821 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:00:59.821 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calie8cee6818cb" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.821 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch-b" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch-b" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calie8cee6818cb" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calie8cee6818cb" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch-b" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch-b" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:00:59.822 [INFO][70] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.822 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:00:59.825 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:59.825 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:59.880 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:00:59.881 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"} status="up"
2019-10-26 14:00:59.881 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=59.348088
2019-10-26 14:00:59.949 [INFO][70] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-10-26 14:01:00.080 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.081 [INFO][70] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:01:00.081 [INFO][70] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:01:00.087 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.036089
2019-10-26 14:01:00.152 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.152 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:00.153 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:00.155 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0436650000000003
2019-10-26 14:01:00.617 [INFO][70] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-10-26 14:01:00.835 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.835 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:00.838 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:00.843 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.574269
2019-10-26 14:01:00.887 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.887 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:00.891 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:00.894 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.581651
2019-10-26 14:01:01.545 [INFO][70] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=10
2019-10-26 14:01:01.839 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.839 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:01.842 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:01.846 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.76488
2019-10-26 14:01:01.888 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.888 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:01.891 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:01.894 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.186881
2019-10-26 14:01:02.152 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:02.152 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:02.155 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:02.159 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.194737
2019-10-26 14:01:03.838 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:03.839 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:03.841 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:03.845 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.779153
2019-10-26 14:01:03.887 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:03.887 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:03.888 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:03.890 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7578519999999997
2019-10-26 14:01:06.149 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:06.149 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:06.152 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:06.154 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.248799
2019-10-26 14:01:07.600 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:07.600 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:07.600 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:07.600 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:07.600 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:07.602 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.006157ms
2019-10-26 14:01:07.603 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.681742ms
2019-10-26 14:01:07.603 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.239411
2019-10-26 14:01:07.832 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:07.832 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:07.834 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:07.837 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.1148180000000005
2019-10-26 14:01:07.886 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:07.886 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:07.887 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:07.891 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.732612
2019-10-26 14:01:08.216 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-5mrgs, name=eth0)
2019-10-26 14:01:08.216 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-5mrgs" endpoint_id:"eth0" > endpoint:<state:"active" name:"calibd967d734cf" mac:"62:f8:25:00:45:ed" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-10-26 14:01:08.216 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.216 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.216 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calibd967d734cf" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.216 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:08.216 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calibd967d734cf" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.217 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.217 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:01:08.217 [INFO][70] 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-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.217 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.217 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.217 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calibd967d734cf" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.217 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:08.217 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calibd967d734cf" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.217 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calibd967d734cf"
2019-10-26 14:01:08.218 [INFO][70] 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-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.218 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"}
2019-10-26 14:01:08.220 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-r46ls, name=eth0)
2019-10-26 14:01:08.220 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.224 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.225 [INFO][70] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-fkm4q, name=eth0)
2019-10-26 14:01:08.228 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:08.229 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-5mrgs", EndpointId:"eth0"} status="up"
2019-10-26 14:01:08.229 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=12.357555
2019-10-26 14:01:08.229 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-r46ls" endpoint_id:"eth0" > endpoint:<state:"active" name:"calie8cee6818cb" mac:"d6:cf:6a:81:a5:d9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-10-26 14:01:08.229 [INFO][70] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-fkm4q" endpoint_id:"eth0" > endpoint:<state:"active" name:"calib68953dea40" mac:"36:6f:a1:e0:28:25" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-10-26 14:01:08.229 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.229 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.229 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calie8cee6818cb" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.229 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:08.229 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calie8cee6818cb" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.229 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.229 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.229 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calib68953dea40" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.229 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calib68953dea40" ipVersion=0x4 table="filter"
2019-10-26 14:01:08.229 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.229 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] 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-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calie8cee6818cb" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.230 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:08.230 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calie8cee6818cb" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-tw-calib68953dea40" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.230 [INFO][70] table.go 417: Queueing update of chain. chainName="cali-fw-calib68953dea40" ipVersion=0x6 table="filter"
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.230 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calie8cee6818cb"
2019-10-26 14:01:08.231 [INFO][70] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calib68953dea40"
2019-10-26 14:01:08.231 [INFO][70] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.231 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"}
2019-10-26 14:01:08.231 [INFO][70] 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-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.231 [INFO][70] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"}
2019-10-26 14:01:08.232 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.233 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.237 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:08.237 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-r46ls", EndpointId:"eth0"} status="up"
2019-10-26 14:01:08.237 [INFO][70] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:08.237 [INFO][70] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-fkm4q", EndpointId:"eth0"} status="up"
2019-10-26 14:01:08.237 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.533157
2019-10-26 14:01:14.153 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:14.153 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:14.157 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:14.160 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.058077
2019-10-26 14:01:15.839 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:15.840 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:15.842 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:15.845 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.709172000000001
2019-10-26 14:01:15.886 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:15.886 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:15.887 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:15.890 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.53004
2019-10-26 14:01:18.199 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:18.199 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:18.199 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:18.199 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:18.199 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:18.202 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.230729ms
2019-10-26 14:01:18.203 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.532286ms
2019-10-26 14:01:18.204 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.214678
2019-10-26 14:01:28.349 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:28.350 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:28.350 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:28.350 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:28.350 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:28.353 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.623012ms
2019-10-26 14:01:28.353 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.401668ms
2019-10-26 14:01:28.353 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4873909999999997
2019-10-26 14:01:29.906 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.907 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:01:29.910 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:01:29.911 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.671911
2019-10-26 14:01:30.114 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.114 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:01:30.116 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:01:30.119 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.894887
2019-10-26 14:01:30.143 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.143 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:01:30.145 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:01:30.148 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.551991
2019-10-26 14:01:30.151 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.151 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:30.152 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:30.155 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.837875
2019-10-26 14:01:30.329 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.329 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:01:30.330 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:01:30.332 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.890321
2019-10-26 14:01:30.340 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:01:30.341 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:01:30.343 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7084029999999997
2019-10-26 14:01:31.836 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:31.836 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:31.839 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:31.843 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.359466
2019-10-26 14:01:31.887 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:31.887 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:31.889 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:31.894 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.712178
2019-10-26 14:01:38.389 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:38.389 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:38.389 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:38.389 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:38.390 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:38.392 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.122517ms
2019-10-26 14:01:38.392 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.145235ms
2019-10-26 14:01:38.392 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.960814
2019-10-26 14:01:48.741 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:48.741 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:48.741 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:48.741 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:48.741 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:48.744 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.646651ms
2019-10-26 14:01:48.745 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.197142ms
2019-10-26 14:01:48.745 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.80987
2019-10-26 14:01:59.404 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:59.404 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:59.404 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:59.404 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:59.404 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:59.406 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.640988ms
2019-10-26 14:01:59.407 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.37608ms
2019-10-26 14:01:59.407 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.682265
2019-10-26 14:02:02.146 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:02.147 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:02:02.149 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:02:02.153 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.978033
2019-10-26 14:02:03.839 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:03.839 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:02:03.841 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:02:03.845 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.513031
2019-10-26 14:02:03.886 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:03.886 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:02:03.888 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:02:03.893 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.556177
2019-10-26 14:02:10.352 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:10.352 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:10.352 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:10.352 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:10.352 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:10.354 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.2907ms
2019-10-26 14:02:10.354 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.575072ms
2019-10-26 14:02:10.354 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.09112
2019-10-26 14:02:20.763 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:20.763 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:20.763 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:20.763 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:20.763 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:20.765 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.301771ms
2019-10-26 14:02:20.765 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.386979ms
2019-10-26 14:02:20.765 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.6450550000000002
2019-10-26 14:02:31.387 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:31.387 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:31.387 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:31.387 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:31.387 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:31.390 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.048928ms
2019-10-26 14:02:31.390 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.343093ms
2019-10-26 14:02:31.391 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.986295
2019-10-26 14:02:38.599 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:38.599 [INFO][70] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:02:38.599 [INFO][70] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:02:38.602 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8912619999999998
2019-10-26 14:02:41.531 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:41.531 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:41.531 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:41.531 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:41.531 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:41.534 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.029625ms
2019-10-26 14:02:41.535 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.172178ms
2019-10-26 14:02:41.535 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.290768
2019-10-26 14:02:52.502 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:52.502 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:52.502 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:52.502 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:52.503 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:52.505 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.707314ms
2019-10-26 14:02:52.507 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.827356ms
2019-10-26 14:02:52.507 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.569178999999999
2019-10-26 14:02:59.910 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.911 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-10-26 14:02:59.912 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:02:59.913 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.727359
2019-10-26 14:03:00.119 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.119 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-10-26 14:03:00.121 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:03:00.123 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.034307
2019-10-26 14:03:00.149 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.149 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-10-26 14:03:00.151 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:03:00.153 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6950220000000003
2019-10-26 14:03:00.334 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.335 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-10-26 14:03:00.337 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:03:00.340 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.586346
2019-10-26 14:03:00.347 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.347 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-10-26 14:03:00.348 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:03:00.350 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.013388
2019-10-26 14:03:02.597 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:02.597 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:02.597 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:02.597 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:02.597 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:02.599 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.501044ms
2019-10-26 14:03:02.599 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.871786ms
2019-10-26 14:03:02.599 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.344411
2019-10-26 14:03:06.146 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:06.146 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:03:06.148 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:03:06.151 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.901763
2019-10-26 14:03:07.837 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:07.837 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:03:07.839 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:03:07.842 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.860887
2019-10-26 14:03:07.885 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:07.886 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:03:07.887 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:03:07.890 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.203005
2019-10-26 14:03:13.441 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:13.441 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:13.442 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:13.442 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:13.442 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:13.443 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.546701ms
2019-10-26 14:03:13.444 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.792775ms
2019-10-26 14:03:13.444 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.618189
2019-10-26 14:03:24.029 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:24.029 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:24.029 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:24.029 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:24.029 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:24.031 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.605823ms
2019-10-26 14:03:24.032 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.307984ms
2019-10-26 14:03:24.032 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.881051
2019-10-26 14:03:34.482 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:34.482 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:34.482 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:34.483 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:34.483 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:34.485 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.382754ms
2019-10-26 14:03:34.485 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.519828ms
2019-10-26 14:03:34.486 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.834621
2019-10-26 14:03:37.907 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.908 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:03:37.909 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:03:37.911 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.835857
2019-10-26 14:03:38.113 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.113 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:03:38.115 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:03:38.117 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.008201000000001
2019-10-26 14:03:38.142 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.143 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:03:38.145 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:03:38.148 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.738815000000001
2019-10-26 14:03:38.331 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.331 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:03:38.333 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:03:38.334 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.647226
2019-10-26 14:03:38.340 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.340 [INFO][70] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:03:38.342 [INFO][70] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:03:38.344 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.063134000000001
2019-10-26 14:03:45.307 [INFO][70] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:45.308 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:45.308 [INFO][70] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:45.308 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:45.308 [INFO][70] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:45.310 [INFO][70] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.637235ms
2019-10-26 14:03:45.311 [INFO][70] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.573879ms
2019-10-26 14:03:45.311 [INFO][70] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.203599
