2019-05-18 16:38:07.181 [INFO][71] 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:"7b859c7918434ccc80d486a120b41883", 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{"etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"ctl01"}, 0x3:map[string]string{"MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None"}, 0x1:map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "CalicoVersion":"v3.3.2", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "LogSeverityFile":"None", "LogSeveritySys":"None", "DefaultEndpointToHostAction":"Return", "LogSeverityScreen":"Info", "FelixHostname":"ctl01", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "LogFilePath":"None", "ClusterType":"k8s,bgp", "ReportingIntervalSecs":"0", "EtcdEndpoints":"https://172.16.10.36:4001", "EtcdCaFile":"/var/lib/etcd/ca.pem", "MetadataAddr":"None"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-05-18 16:38:07.182 [INFO][71] driver.go 43: Using internal (linux) dataplane driver.
2019-05-18 16:38:07.182 [INFO][71] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-05-18 16:38:07.182 [INFO][71] 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)(0xc4200c6640), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200c6730), 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)(0xc42054db80), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-05-18 16:38:07.182 [INFO][71] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4200c6640), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200c6730), 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-05-18 16:38:07.182 [INFO][71] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-05-18 16:38:07.182 [INFO][71] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-05-18 16:38:07.182 [INFO][71] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-05-18 16:38:07.184 [INFO][71] 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-05-18 16:38:07.185 [INFO][71] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:07.185 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:07.185 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:07.186 [INFO][71] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:07.186 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:07.186 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:07.186 [INFO][71] int_dataplane.go 424: Registering to report health.
2019-05-18 16:38:07.186 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.187 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.188 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.189 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.189 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.190 [INFO][71] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.190 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.191 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.191 [INFO][71] daemon.go 299: Connect to the dataplane driver.
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 981: Started internal status report thread
2019-05-18 16:38:07.191 [INFO][71] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc42056e080), (*watchersyncer.watcherCache)(0xc42056e100), (*watchersyncer.watcherCache)(0xc42056e180), (*watchersyncer.watcherCache)(0xc42056e200), (*watchersyncer.watcherCache)(0xc42056e280), (*watchersyncer.watcherCache)(0xc42056e300), (*watchersyncer.watcherCache)(0xc42056e380), (*watchersyncer.watcherCache)(0xc42056e480), (*watchersyncer.watcherCache)(0xc42056e500), (*watchersyncer.watcherCache)(0xc42056e580)}, results:(chan interface {})(0xc4200aa4e0), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc4205720c0), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 983: Process status reports disabled
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-05-18 16:38:07.191 [INFO][71] iface_monitor.go 88: Interface monitoring thread started.
2019-05-18 16:38:07.191 [INFO][71] calc_graph.go 96: Creating calculation graph, filtered to hostname ctl01
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-05-18 16:38:07.191 [INFO][71] iface_monitor.go 95: Subscribed to netlink updates.
2019-05-18 16:38:07.191 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:07.191 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:07.191 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:07.191 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:07.191 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-05-18 16:38:07.191 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"::1":set.empty{}, "127.0.0.1":set.empty{}} ifaceName="lo"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe9d:addf":set.empty{}, "192.168.11.21":set.empty{}} ifaceName="ens3"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}} ifaceName="ens4"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}} ifaceName="ens5"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-05-18 16:38:07.192 [INFO][71] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:07.192 [INFO][71] daemon.go 439: Starting the datastore Syncer
2019-05-18 16:38:07.192 [INFO][71] watchersyncer.go 89: Start called
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fef8:33c0":set.empty{}} ifaceName="br-mgmt"
2019-05-18 16:38:07.192 [INFO][71] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-05-18 16:38:07.192 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-05-18 16:38:07.192 [INFO][71] daemon.go 454: Started the processing graph
2019-05-18 16:38:07.193 [INFO][71] daemon.go 813: Reading from dataplane driver pipe...
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}} ifaceName="ens5.1000"
2019-05-18 16:38:07.193 [INFO][71] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-05-18 16:38:07.193 [INFO][71] watchersyncer.go 147: Starting main event processing loop
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-05-18 16:38:07.193 [INFO][71] async_calc_graph.go 134: AsyncCalcGraph running
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-05-18 16:38:07.193 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-05-18 16:38:07.197 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-05-18 16:38:07.197 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-05-18 16:38:07.198 [INFO][71] watchersyncer.go 127: Sending status update Status=resync
2019-05-18 16:38:07.198 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.198 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.198 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-05-18 16:38:07.198 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.198 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-05-18 16:38:07.198 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-05-18 16:38:07.199 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-05-18 16:38:07.199 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-05-18 16:38:07.199 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-05-18 16:38:07.194 [INFO][71] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"7b859c7918434ccc80d486a120b41883" > 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-05-18 16:38:07.199 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-05-18 16:38:07.199 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.199 [INFO][71] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-05-18 16:38:07.200 [INFO][71] config_batcher.go 61: Host config update for this host: {{HostConfig(node=ctl01,name=DefaultEndpointToHostAction) Return 12 0s} 1}
2019-05-18 16:38:07.200 [INFO][71] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 7b859c7918434ccc80d486a120b41883 6 0s} 1}
2019-05-18 16:38:07.200 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-05-18 16:38:07.200 [INFO][71] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-05-18 16:38:07.200 [INFO][71] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-05-18 16:38:07.200 [INFO][71] 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-05-18 16:38:07.200 [INFO][71] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-05-18 16:38:07.200 [INFO][71] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:07.200 [INFO][71] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-05-18 16:38:07.201 [INFO][71] watchersyncer.go 127: Sending status update Status=in-sync
2019-05-18 16:38:07.201 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.201 [INFO][71] config_batcher.go 102: Datamodel in sync, flushing config update
2019-05-18 16:38:07.201 [INFO][71] 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-05-18 16:38:07.201 [INFO][71] config_batcher.go 112: Sending config update global: map[ClusterGUID:7b859c7918434ccc80d486a120b41883 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[DefaultEndpointToHostAction:Return].
2019-05-18 16:38:07.201 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.201 [INFO][71] async_calc_graph.go 160: First time we've been in sync
2019-05-18 16:38:07.201 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe9d:addf":set.empty{}, "192.168.11.21":set.empty{}}}
2019-05-18 16:38:07.201 [INFO][71] event_sequencer.go 210: Possible config update. global=map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-05-18 16:38:07.201 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.21":set.empty{}, "fe80::5054:ff:fe9d:addf":set.empty{}}}
2019-05-18 16:38:07.201 [INFO][71] config_params.go 217: Merging in config from datastore (global): map[ReportingIntervalSecs:0 ClusterGUID:7b859c7918434ccc80d486a120b41883 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info]
2019-05-18 16:38:07.201 [INFO][71] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:07.201 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:07.201 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.201 [INFO][71] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:07.201 [INFO][71] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:07.201 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.21":set.empty{}, "fe80::5054:ff:fe9d:addf":set.empty{}}}
2019-05-18 16:38:07.201 [INFO][71] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.202 [INFO][71] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:07.202 [INFO][71] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:07.202 [INFO][71] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:07.202 [INFO][71] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:07.202 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.202 [INFO][71] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.203 [INFO][71] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.203 [INFO][71] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:07.203 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.204 [INFO][71] daemon.go 546: No driver process to monitor
2019-05-18 16:38:07.204 [INFO][71] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:07.204 [INFO][71] usagerep.go 83: Waiting before first check-in delay=5m2.95s
2019-05-18 16:38:07.204 [INFO][71] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:07.204 [INFO][71] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:07.204 [INFO][71] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:07.204 [INFO][71] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:07.204 [INFO][71] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:07.204 [INFO][71] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:07.205 [INFO][71] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:07.204 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}}}
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}}}
2019-05-18 16:38:07.205 [INFO][71] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:07.205 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.205 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}}}
2019-05-18 16:38:07.205 [INFO][71] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:07.205 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.205 [INFO][71] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:07.205 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.205 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:07.206 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}, "172.16.10.36":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}, "172.16.10.36":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fef8:33c0":set.empty{}, "172.16.10.36":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.206 [INFO][71] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:07.206 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.206 [INFO][71] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-05-18 16:38:07.206 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.207 [INFO][71] daemon.go 892: Datastore now in sync.
2019-05-18 16:38:07.207 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.207 [INFO][71] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-05-18 16:38:07.207 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe60:dbe8":set.empty{}}}
2019-05-18 16:38:07.207 [INFO][71] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-05-18 16:38:07.207 [INFO][71] 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-05-18 16:38:07.207 [INFO][71] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fdb5:2435:a955::-48" pool:<cidr:"fdb5:2435:a955::/48" > 
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=160.106363ms
2019-05-18 16:38:07.207 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:07.207 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.207 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.207 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.208 [INFO][71] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.208 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.209 [INFO][71] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-05-18 16:38:07.209 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.209 [INFO][71] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:07.209 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:07.209 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:07.209 [INFO][71] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:07.225 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=15.588842ms
2019-05-18 16:38:07.225 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=15.478282ms
2019-05-18 16:38:07.225 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.225 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-05-18 16:38:07.225 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-05-18 16:38:07.226 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-05-18 16:38:07.226 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-05-18 16:38:07.226 [INFO][71] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.413 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:07.416 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:07.417 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:07.419 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.424 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.431 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:07.432 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:07.434 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:07.962 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=755.0216720000001
2019-05-18 16:38:07.963 [INFO][71] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.915307185
2019-05-18 16:38:09.043 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:09.043 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:09.044 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:09.045 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:09.048 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:09.049 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:09.053 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:09.054 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:09.055 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:09.056 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:09.058 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=14.846849
2019-05-18 16:38:09.506 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.507 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:09.508 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:09.509 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5692190000000004
2019-05-18 16:38:09.514 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.514 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:09.515 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:09.516 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2981030000000002
2019-05-18 16:38:09.714 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.714 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:09.715 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:09.717 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.155879
2019-05-18 16:38:09.723 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.723 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:09.730 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:09.733 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.553872
2019-05-18 16:38:09.742 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.742 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:09.742 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:09.743 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:09.744 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:09.745 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.018654
2019-05-18 16:38:09.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.927 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:09.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:09.930 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9895669999999996
2019-05-18 16:38:09.965 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.966 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:09.968 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:09.970 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.092306000000001
2019-05-18 16:38:11.496 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.496 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:11.498 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:11.499 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.402696
2019-05-18 16:38:11.515 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.515 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:11.516 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:11.518 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5828610000000003
2019-05-18 16:38:11.714 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.714 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:11.716 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:11.717 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.202772
2019-05-18 16:38:11.723 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.723 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:11.725 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:11.728 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.607476
2019-05-18 16:38:11.737 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.737 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:11.738 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:11.740 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.525867
2019-05-18 16:38:11.745 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.745 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:11.746 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:11.748 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.737339
2019-05-18 16:38:11.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:11.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:11.929 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.86342
2019-05-18 16:38:11.965 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.965 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:11.967 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:11.969 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9447240000000003
2019-05-18 16:38:15.496 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.496 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:15.498 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:15.500 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7705830000000002
2019-05-18 16:38:15.515 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.516 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:15.516 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:15.519 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6970140000000002
2019-05-18 16:38:15.715 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.715 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:15.717 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:15.719 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.258301
2019-05-18 16:38:15.724 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.724 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:15.727 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:15.730 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.9660210000000005
2019-05-18 16:38:15.737 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.738 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:15.739 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:15.741 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.5932820000000003
2019-05-18 16:38:15.745 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.745 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:15.747 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:15.748 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6487149999999997
2019-05-18 16:38:15.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:15.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:15.931 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.258312999999999
2019-05-18 16:38:15.967 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.967 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:15.968 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:15.970 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.585775
2019-05-18 16:38:17.715 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:17.715 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:17.715 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:17.715 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:17.715 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:17.717 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.589471ms
2019-05-18 16:38:17.717 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.740168ms
2019-05-18 16:38:17.717 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1257989999999998
2019-05-18 16:38:23.492 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.492 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:23.493 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:23.495 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.787421
2019-05-18 16:38:23.514 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.514 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:23.517 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:23.519 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.4610650000000005
2019-05-18 16:38:23.716 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.716 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:23.717 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:23.718 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.477711
2019-05-18 16:38:23.722 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.722 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:23.723 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:23.724 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.175401
2019-05-18 16:38:23.734 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.735 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:23.735 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:23.737 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.210165
2019-05-18 16:38:23.744 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.744 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:23.745 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:23.746 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.100807
2019-05-18 16:38:23.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:23.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:23.929 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.537166
2019-05-18 16:38:23.966 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.966 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:23.967 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:23.968 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.462084
2019-05-18 16:38:28.311 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:28.311 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:28.311 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:28.311 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:28.311 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:28.312 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.197063ms
2019-05-18 16:38:28.312 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.252371ms
2019-05-18 16:38:28.312 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.686109
2019-05-18 16:38:39.231 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.231 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:39.231 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:39.231 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:39.231 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:39.232 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.24673ms
2019-05-18 16:38:39.232 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.348168ms
2019-05-18 16:38:39.233 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.835548
2019-05-18 16:38:39.492 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.492 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:39.493 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:39.495 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.939368
2019-05-18 16:38:39.514 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.514 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:39.515 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:39.517 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.766045
2019-05-18 16:38:39.714 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.714 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:39.716 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:39.717 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.30904
2019-05-18 16:38:39.723 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.723 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:39.725 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:39.727 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8137269999999996
2019-05-18 16:38:39.736 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.736 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:39.738 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:39.740 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.600557
2019-05-18 16:38:39.745 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.745 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:39.746 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:39.747 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.071657
2019-05-18 16:38:39.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:39.927 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:39.928 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.391501
2019-05-18 16:38:39.965 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.965 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:39.966 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:39.967 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.215714
2019-05-18 16:38:50.150 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:50.150 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:50.150 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:50.150 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:50.150 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:50.152 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.658965ms
2019-05-18 16:38:50.152 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.283298ms
2019-05-18 16:38:50.153 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5650920000000004
2019-05-18 16:39:01.126 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:01.127 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:01.127 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:01.127 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:01.127 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:01.128 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.677676ms
2019-05-18 16:39:01.129 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.543633ms
2019-05-18 16:39:01.129 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.334986
2019-05-18 16:39:11.231 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.231 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:11.231 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:11.231 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:11.232 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:11.234 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.237924ms
2019-05-18 16:39:11.234 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.033297ms
2019-05-18 16:39:11.235 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.306986
2019-05-18 16:39:11.492 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.492 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:39:11.494 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:39:11.497 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.733206999999999
2019-05-18 16:39:11.516 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.517 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:39:11.519 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:39:11.522 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.567856000000001
2019-05-18 16:39:11.717 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.717 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:11.718 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:11.720 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-05-18 16:39:11.721 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.761092
2019-05-18 16:39:11.724 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.724 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:11.725 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:11.727 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-05-18 16:39:11.728 [WARNING][71] 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-05-18 16:39:11.729 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.228643
2019-05-18 16:39:11.737 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.738 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:39:11.739 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:39:11.740 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.476605
2019-05-18 16:39:11.744 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.744 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:39:11.745 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:39:11.747 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.408466
2019-05-18 16:39:11.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:39:11.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:39:11.931 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.1472690000000005
2019-05-18 16:39:11.968 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.968 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:39:11.970 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:39:11.972 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.804521
2019-05-18 16:39:12.726 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.726 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:12.728 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:12.734 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.94193
2019-05-18 16:39:12.737 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.737 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:12.738 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:12.740 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7248889999999997
2019-05-18 16:39:13.723 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.724 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:13.726 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:13.729 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.065239
2019-05-18 16:39:13.734 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.734 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:13.735 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:13.737 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.715039
2019-05-18 16:39:15.724 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.724 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:15.725 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:15.726 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.444068
2019-05-18 16:39:15.731 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.731 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:15.732 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:15.736 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.578022
2019-05-18 16:39:19.726 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.726 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:19.727 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:19.729 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.942116
2019-05-18 16:39:19.732 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.732 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:19.733 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:19.736 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.764066
2019-05-18 16:39:21.757 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:21.758 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:21.758 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:21.758 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:21.758 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:21.761 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.494787ms
2019-05-18 16:39:21.761 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.868218ms
2019-05-18 16:39:21.762 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.178077
2019-05-18 16:39:27.722 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.722 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:27.724 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:27.726 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.341017
2019-05-18 16:39:27.733 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.733 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:27.734 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:27.736 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.083942
2019-05-18 16:39:32.221 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:32.221 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:32.221 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:32.221 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:32.222 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:32.223 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.391888ms
2019-05-18 16:39:32.223 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.483713ms
2019-05-18 16:39:32.223 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.288654
2019-05-18 16:39:39.705 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:39.706 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:39:39.706 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:39:39.706 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.392307
2019-05-18 16:39:42.454 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:42.454 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:42.454 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:42.454 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:42.455 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:42.456 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.234381ms
2019-05-18 16:39:42.456 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.125081ms
2019-05-18 16:39:42.456 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.841866
2019-05-18 16:39:43.721 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.721 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:43.722 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:43.724 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9215310000000003
2019-05-18 16:39:43.732 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.732 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:43.733 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:43.736 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.98742
2019-05-18 16:39:52.603 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:52.604 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:52.604 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:52.604 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:52.604 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:52.605 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.03414ms
2019-05-18 16:39:52.606 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.615047ms
2019-05-18 16:39:52.606 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.149568
2019-05-18 16:40:02.998 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:02.998 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:02.998 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:02.998 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:02.998 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:03.000 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.657038ms
2019-05-18 16:40:03.000 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.739232ms
2019-05-18 16:40:03.000 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.124243
2019-05-18 16:40:13.964 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:13.964 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:13.964 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:13.964 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:13.964 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:13.965 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.012009ms
2019-05-18 16:40:13.966 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.222483ms
2019-05-18 16:40:13.966 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.749896
2019-05-18 16:40:15.492 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.492 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:40:15.493 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:40:15.495 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.807305
2019-05-18 16:40:15.514 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.514 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:15.516 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:15.518 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9585799999999995
2019-05-18 16:40:15.725 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.725 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:15.726 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:15.728 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-05-18 16:40:15.728 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-05-18 16:40:15.729 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.26504
2019-05-18 16:40:15.733 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.733 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:15.735 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:40:15.735 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:15.737 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:40:15.737 [WARNING][71] 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-05-18 16:40:15.737 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-05-18 16:40:15.737 [WARNING][71] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-05-18 16:40:15.739 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.675674000000001
2019-05-18 16:40:15.747 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.747 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:40:15.748 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:40:15.749 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.0395909999999997
2019-05-18 16:40:15.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:40:15.927 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:40:15.928 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8049239999999998
2019-05-18 16:40:15.965 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.965 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:40:15.970 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:40:15.971 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.045973
2019-05-18 16:40:16.735 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.735 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:16.736 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:16.738 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6726430000000003
2019-05-18 16:40:16.741 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.741 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:16.742 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:16.744 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3709870000000004
2019-05-18 16:40:17.732 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.732 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:17.734 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:17.739 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.347322
2019-05-18 16:40:17.746 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.746 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:17.747 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:17.748 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4411329999999998
2019-05-18 16:40:19.732 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.732 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:19.734 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:19.737 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.806907
2019-05-18 16:40:19.743 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.743 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:19.745 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:19.747 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.780228
2019-05-18 16:40:21.560 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.560 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{}}
2019-05-18 16:40:21.560 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{}}
2019-05-18 16:40:21.560 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{}}
2019-05-18 16:40:21.560 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:21.560 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.560 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="cali6f3049528bd" state="up"
2019-05-18 16:40:21.564 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.156744000000001
2019-05-18 16:40:21.564 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali6f3049528bd", State:"up"}
2019-05-18 16:40:21.564 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:21.564 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.564 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.565 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.565 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.565 [INFO][71] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="cali6f3049528bd" ipVersion=0x4
2019-05-18 16:40:21.565 [INFO][71] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali6f3049528bd" ipVersion=0x4
2019-05-18 16:40:21.565 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.968625
2019-05-18 16:40:21.566 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-qmnnm, name=eth0)
2019-05-18 16:40:21.566 [WARNING][71] active_rules_calculator.go 326: Profile not known or invalid, generating dummy profile that drops all traffic. profileID="calico-k8s-network"
2019-05-18 16:40:21.565 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:21.566 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:21.566 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali6f3049528bd", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:21.566 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:21.567 [INFO][71] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="cali6f3049528bd" ipVersion=0x4
2019-05-18 16:40:21.567 [INFO][71] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali6f3049528bd" ipVersion=0x4
2019-05-18 16:40:21.567 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.232995
2019-05-18 16:40:21.567 [INFO][71] 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-05-18 16:40:21.567 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.567 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:21.567 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.567 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.567 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:21.567 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.567 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-qmnnm" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali6f3049528bd" mac:"a2:cb:67:5a:bd:40" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-05-18 16:40:21.567 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:21.567 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.567 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali6f3049528bd" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali6f3049528bd" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.568 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.568 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.568 [INFO][71] 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-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali6f3049528bd" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali6f3049528bd" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.568 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.568 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.568 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:21.568 [INFO][71] 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-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.568 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:21.572 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:21.575 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:21.580 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:21.580 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"} status="up"
2019-05-18 16:40:21.581 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=13.083592999999999
2019-05-18 16:40:21.581 [INFO][71] 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-05-18 16:40:21.581 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.581 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:21.581 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:21.581 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.581 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:21.581 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:21.581 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:21.584 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:21.585 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:21.588 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.660508
2019-05-18 16:40:22.593 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.593 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:22.594 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:22.595 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.596 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.604 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.656568
2019-05-18 16:40:22.605 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-6ssv4, name=eth0)
2019-05-18 16:40:22.605 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-6ssv4" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali899f7e4a841" mac:"ba:c0:7b:27:67:c9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-05-18 16:40:22.605 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali899f7e4a841" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.605 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali899f7e4a841" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 807: Skipping configuration of interface because it is oper down. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=false status="down" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="down" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali899f7e4a841" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.605 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali899f7e4a841" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.605 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.605 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.606 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.606 [INFO][71] endpoint_mgr.go 807: Skipping configuration of interface because it is oper down. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.606 [INFO][71] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=false status="down" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.606 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="down" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.603 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.606 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="cali899f7e4a841" state="up"
2019-05-18 16:40:22.607 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.613 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.621 [INFO][71] status_combiner.go 78: Endpoint down for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} ipVersion=0x4 status="down"
2019-05-18 16:40:22.621 [INFO][71] status_combiner.go 78: Endpoint down for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} ipVersion=0x6 status="down"
2019-05-18 16:40:22.621 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} status="down"
2019-05-18 16:40:22.621 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.066532000000002
2019-05-18 16:40:22.621 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali899f7e4a841", State:"up"}
2019-05-18 16:40:22.621 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 291: Workload interface state changed; marking for status update. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] 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-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.621 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 291: Workload interface state changed; marking for status update. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali899f7e4a841"
2019-05-18 16:40:22.621 [INFO][71] 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-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.622 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:22.622 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:22.622 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} status="up"
2019-05-18 16:40:22.622 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.334661
2019-05-18 16:40:22.622 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali899f7e4a841", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.622 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali899f7e4a841", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.622 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali899f7e4a841", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.623 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.623 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.08372
2019-05-18 16:40:22.844 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calidca13f2d506"
2019-05-18 16:40:22.844 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{}}
2019-05-18 16:40:22.844 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{}}
2019-05-18 16:40:22.844 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{}}
2019-05-18 16:40:22.844 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.844 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.159495
2019-05-18 16:40:22.847 [INFO][71] int_dataplane.go 471: Linux interface state changed. ifaceName="calidca13f2d506" state="up"
2019-05-18 16:40:22.847 [INFO][71] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calidca13f2d506"
2019-05-18 16:40:22.847 [INFO][71] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calidca13f2d506", State:"up"}
2019-05-18 16:40:22.847 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.847 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.847 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.847 [INFO][71] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.848 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.848 [INFO][71] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.2/32 ifaceName="calidca13f2d506" ipVersion=0x4
2019-05-18 16:40:22.848 [INFO][71] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calidca13f2d506" ipVersion=0x4
2019-05-18 16:40:22.848 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.7383959999999999
2019-05-18 16:40:22.848 [INFO][71] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.848 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.848 [INFO][71] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calidca13f2d506", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.848 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.848 [INFO][71] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.2/32 ifaceName="calidca13f2d506" ipVersion=0x4
2019-05-18 16:40:22.848 [INFO][71] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calidca13f2d506" ipVersion=0x4
2019-05-18 16:40:22.848 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.228288
2019-05-18 16:40:22.851 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-nqgxn, name=eth0)
2019-05-18 16:40:22.851 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-nqgxn" endpoint_id:"eth0" > endpoint:<state:"active" name:"calidca13f2d506" mac:"0a:78:8c:87:e9:25" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-05-18 16:40:22.851 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.851 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.851 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-calidca13f2d506" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.851 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:22.851 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-calidca13f2d506" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.851 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.852 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.852 [INFO][71] 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-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-calidca13f2d506" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.852 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-calidca13f2d506" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.852 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.852 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.852 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:22.852 [INFO][71] 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-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.852 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:22.856 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.857 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.862 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:22.862 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"} status="up"
2019-05-18 16:40:22.862 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=10.665243
2019-05-18 16:40:23.240 [INFO][71] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-05-18 16:40:23.739 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.739 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:23.741 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:23.745 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.72099
2019-05-18 16:40:23.865 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.865 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:23.865 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:23.869 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:23.876 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:23.877 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=12.376522
2019-05-18 16:40:23.967 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.967 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:23.967 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:23.967 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:23.967 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:23.968 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.320663ms
2019-05-18 16:40:23.968 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.526565ms
2019-05-18 16:40:23.969 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.903582
2019-05-18 16:40:24.035 [INFO][71] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-05-18 16:40:24.579 [INFO][71] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=10
2019-05-18 16:40:24.860 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.860 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:24.861 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:24.863 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.158746
2019-05-18 16:40:24.865 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.865 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:24.866 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:24.869 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.617925
2019-05-18 16:40:26.863 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:26.864 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:26.864 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:26.865 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:26.867 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:26.868 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.895094
2019-05-18 16:40:30.106 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-qmnnm, name=eth0)
2019-05-18 16:40:30.106 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-qmnnm" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali6f3049528bd" mac:"a2:cb:67:5a:bd:40" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-05-18 16:40:30.106 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.106 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali6f3049528bd" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.107 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.107 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali6f3049528bd" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.107 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:30.107 [INFO][71] 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-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali6f3049528bd" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.107 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.107 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali6f3049528bd" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.107 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.107 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali6f3049528bd"
2019-05-18 16:40:30.108 [INFO][71] 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-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.108 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"}
2019-05-18 16:40:30.111 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.112 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.115 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.115 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-qmnnm", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.115 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.004573
2019-05-18 16:40:30.195 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-server-7876fb46d4-nqgxn, name=eth0)
2019-05-18 16:40:30.195 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-server-7876fb46d4-nqgxn" endpoint_id:"eth0" > endpoint:<state:"active" name:"calidca13f2d506" mac:"0a:78:8c:87:e9:25" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.2/32" > 
2019-05-18 16:40:30.195 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.196 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.196 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-calidca13f2d506" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.196 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.196 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-calidca13f2d506" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.196 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.196 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:30.196 [INFO][71] 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-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.196 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.197 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.197 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-calidca13f2d506" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.197 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.197 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-calidca13f2d506" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.197 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.197 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calidca13f2d506"
2019-05-18 16:40:30.197 [INFO][71] 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-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.197 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"}
2019-05-18 16:40:30.199 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.200 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.207 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.207 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-server-7876fb46d4-nqgxn", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.207 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.722186
2019-05-18 16:40:30.291 [INFO][71] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-6ssv4, name=eth0)
2019-05-18 16:40:30.292 [INFO][71] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-6ssv4" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali899f7e4a841" mac:"ba:c0:7b:27:67:c9" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.1/32" > 
2019-05-18 16:40:30.292 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.292 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.292 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali899f7e4a841" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.292 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.292 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali899f7e4a841" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.292 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.293 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali899f7e4a841"
2019-05-18 16:40:30.294 [INFO][71] 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-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.295 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.295 [INFO][71] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.295 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-tw-cali899f7e4a841" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.295 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.295 [INFO][71] table.go 417: Queueing update of chain. chainName="cali-fw-cali899f7e4a841" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.295 [INFO][71] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.295 [INFO][71] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali899f7e4a841"
2019-05-18 16:40:30.296 [INFO][71] 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-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.296 [INFO][71] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"}
2019-05-18 16:40:30.297 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.299 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.311 [INFO][71] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.312 [INFO][71] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-6ssv4", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.312 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=20.040676
2019-05-18 16:40:30.876 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.876 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:30.876 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:30.877 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.878 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.881 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.606623
2019-05-18 16:40:31.734 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:31.734 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:31.735 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:31.739 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.929902
2019-05-18 16:40:34.723 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:34.723 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:34.723 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:34.723 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:34.723 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:34.724 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.158078ms
2019-05-18 16:40:34.724 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.284708ms
2019-05-18 16:40:34.724 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.551406
2019-05-18 16:40:38.860 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.861 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:38.863 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:38.866 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.906504
2019-05-18 16:40:38.868 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.868 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:38.869 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:38.874 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.80085
2019-05-18 16:40:44.996 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:44.996 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:44.996 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:44.997 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:44.997 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:44.999 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.326161ms
2019-05-18 16:40:44.999 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.601101ms
2019-05-18 16:40:45.000 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.287403
2019-05-18 16:40:47.729 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:47.730 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:47.732 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:47.736 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.270471
2019-05-18 16:40:54.866 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.866 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:54.866 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:54.868 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:54.869 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:54.872 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.11174
2019-05-18 16:40:55.565 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:55.566 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:55.566 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:55.566 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:55.566 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:55.569 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.739412ms
2019-05-18 16:40:55.569 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.527056ms
2019-05-18 16:40:55.570 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.264844
2019-05-18 16:41:06.194 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:06.194 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:06.194 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:06.194 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:06.194 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:06.196 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.626565ms
2019-05-18 16:41:06.196 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.35001ms
2019-05-18 16:41:06.197 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.832401
2019-05-18 16:41:11.378 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:11.378 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:41:11.379 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:41:11.382 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.84457
2019-05-18 16:41:16.318 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:16.318 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:16.318 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:16.318 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:16.318 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:16.320 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.108596ms
2019-05-18 16:41:16.321 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.936254ms
2019-05-18 16:41:16.321 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.981646
2019-05-18 16:41:19.729 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:19.730 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:41:19.731 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:41:19.733 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6444989999999997
2019-05-18 16:41:26.806 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.806 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:26.806 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:26.806 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:26.807 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:26.808 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.420307ms
2019-05-18 16:41:26.808 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.595138ms
2019-05-18 16:41:26.808 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.204305
2019-05-18 16:41:26.860 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.860 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:41:26.861 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:41:26.864 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9388569999999996
2019-05-18 16:41:26.866 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.866 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:41:26.867 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:41:26.871 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.006221
2019-05-18 16:41:37.402 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:37.402 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:37.402 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:37.402 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:37.403 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:37.404 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.300902ms
2019-05-18 16:41:37.404 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.010653ms
2019-05-18 16:41:37.404 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.655453
2019-05-18 16:41:45.493 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.494 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-05-18 16:41:45.495 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:41:45.497 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.352779
2019-05-18 16:41:45.741 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.743 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-05-18 16:41:45.745 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:41:45.747 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.204913
2019-05-18 16:41:45.753 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.753 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-05-18 16:41:45.754 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:41:45.755 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5451200000000003
2019-05-18 16:41:45.930 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.930 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.932 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:41:45.935 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.937143
2019-05-18 16:41:45.975 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.975 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.977 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:41:45.980 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.931982
2019-05-18 16:41:47.842 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:47.842 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:47.842 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:47.842 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:47.842 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:47.845 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.104868ms
2019-05-18 16:41:47.845 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.740243ms
2019-05-18 16:41:47.845 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.942771
2019-05-18 16:41:57.942 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:57.942 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:57.942 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:57.942 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:57.943 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:57.949 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=6.817509ms
2019-05-18 16:41:57.952 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=6.306547ms
2019-05-18 16:41:57.952 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.894682
2019-05-18 16:42:08.230 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:08.230 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:08.230 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:08.230 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:08.230 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:08.231 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=964.511µs
2019-05-18 16:42:08.231 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.242412ms
2019-05-18 16:42:08.231 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.499021
2019-05-18 16:42:19.036 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:19.036 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:19.036 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:19.036 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:19.036 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:19.037 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.276147ms
2019-05-18 16:42:19.038 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.21956ms
2019-05-18 16:42:19.038 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.005032
2019-05-18 16:42:23.492 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.492 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:42:23.493 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:42:23.495 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.346483
2019-05-18 16:42:23.732 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.733 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:42:23.733 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:42:23.735 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:42:23.736 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:42:23.738 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.875035
2019-05-18 16:42:23.747 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.747 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:42:23.748 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:42:23.749 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.286502
2019-05-18 16:42:23.926 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.926 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:42:23.928 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:42:23.933 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.182469
2019-05-18 16:42:23.970 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.970 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:42:23.971 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:42:23.972 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.345579
2019-05-18 16:42:29.062 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:29.062 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:29.062 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:29.062 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:29.062 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:29.064 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.493968ms
2019-05-18 16:42:29.064 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.604364ms
2019-05-18 16:42:29.064 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.916658
2019-05-18 16:42:30.860 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.860 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:42:30.861 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:42:30.863 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.046137
2019-05-18 16:42:30.865 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.867 [INFO][71] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:42:30.868 [INFO][71] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:42:30.869 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.681813
2019-05-18 16:42:39.279 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:39.279 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:39.279 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:39.279 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:39.279 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:39.282 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.574088ms
2019-05-18 16:42:39.282 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.525099ms
2019-05-18 16:42:39.282 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.232151
2019-05-18 16:42:48.323 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:48.323 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:42:48.323 [INFO][71] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:42:48.329 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.046616
2019-05-18 16:42:49.512 [INFO][71] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:49.512 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:49.512 [INFO][71] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:49.512 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:49.512 [INFO][71] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:49.514 [INFO][71] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.914978ms
2019-05-18 16:42:49.516 [INFO][71] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.41787ms
2019-05-18 16:42:49.516 [INFO][71] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.189665000000001
