2019-05-18 16:38:06.975 [INFO][62] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp001", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"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{"etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"cmp001", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key"}, 0x3:map[string]string{"LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None"}, 0x1:map[string]string{"ReportingIntervalSecs":"0", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "MetadataAddr":"None", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterType":"k8s,bgp", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "FelixHostname":"cmp001", "LogFilePath":"None", "LogSeveritySys":"None", "DefaultEndpointToHostAction":"Return", "EtcdEndpoints":"https://172.16.10.36:4001", "EtcdCaFile":"/var/lib/etcd/ca.pem", "LogSeverityFile":"None"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-05-18 16:38:06.975 [INFO][62] driver.go 43: Using internal (linux) dataplane driver.
2019-05-18 16:38:06.975 [INFO][62] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-05-18 16:38:06.975 [INFO][62] 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)(0xc4207f2550), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4207f2640), 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)(0xc420294480), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-05-18 16:38:06.976 [INFO][62] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4207f2550), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4207f2640), 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:06.976 [INFO][62] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-05-18 16:38:06.976 [INFO][62] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-05-18 16:38:06.976 [INFO][62] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-05-18 16:38:06.978 [INFO][62] 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:06.978 [INFO][62] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:06.978 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.978 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.979 [INFO][62] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:06.979 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.979 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.979 [INFO][62] int_dataplane.go 424: Registering to report health.
2019-05-18 16:38:06.979 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.979 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.979 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.979 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.979 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.980 [INFO][62] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.980 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.981 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.981 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.981 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.981 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-05-18 16:38:06.981 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-05-18 16:38:06.981 [INFO][62] iface_monitor.go 88: Interface monitoring thread started.
2019-05-18 16:38:06.981 [INFO][62] iface_monitor.go 95: Subscribed to netlink updates.
2019-05-18 16:38:06.981 [INFO][62] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-05-18 16:38:06.981 [INFO][62] daemon.go 299: Connect to the dataplane driver.
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 981: Started internal status report thread
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 983: Process status reports disabled
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-05-18 16:38:06.982 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-05-18 16:38:06.982 [INFO][62] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4203f0080), (*watchersyncer.watcherCache)(0xc4203f0180), (*watchersyncer.watcherCache)(0xc4203f0200), (*watchersyncer.watcherCache)(0xc4203f0280), (*watchersyncer.watcherCache)(0xc4203f0300), (*watchersyncer.watcherCache)(0xc4203f0380), (*watchersyncer.watcherCache)(0xc4203f0400), (*watchersyncer.watcherCache)(0xc4203f0480), (*watchersyncer.watcherCache)(0xc4203f0500), (*watchersyncer.watcherCache)(0xc4203f0580)}, results:(chan interface {})(0xc4200823c0), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc4207f4070), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-05-18 16:38:06.982 [INFO][62] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp001
2019-05-18 16:38:06.982 [INFO][62] 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:06.982 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-05-18 16:38:06.982 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:06.982 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:06.982 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:06.982 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:06.982 [INFO][62] 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:06.983 [INFO][62] 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:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe13:d19f":set.empty{}} ifaceName="ens3"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe4d:a56c":set.empty{}} ifaceName="ens4"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-05-18 16:38:06.983 [INFO][62] 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:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.983 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}} ifaceName="ens5"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe13:d19f":set.empty{}}}
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.983 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-05-18 16:38:06.983 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe13:d19f":set.empty{}}}
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:06.983 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:06.983 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe13:d19f":set.empty{}}}
2019-05-18 16:38:06.983 [INFO][62] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe4d:a56c":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe4d:a56c":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe4d:a56c":set.empty{}} ifaceName="br-mgmt"
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe4d:a56c":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}} ifaceName="ens5.1000"
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] daemon.go 439: Starting the datastore Syncer
2019-05-18 16:38:06.984 [INFO][62] watchersyncer.go 89: Start called
2019-05-18 16:38:06.984 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.984 [INFO][62] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.984 [INFO][62] daemon.go 454: Started the processing graph
2019-05-18 16:38:06.984 [INFO][62] async_calc_graph.go 134: AsyncCalcGraph running
2019-05-18 16:38:06.984 [INFO][62] daemon.go 813: Reading from dataplane driver pipe...
2019-05-18 16:38:06.984 [INFO][62] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-05-18 16:38:06.984 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.984 [INFO][62] watchersyncer.go 147: Starting main event processing loop
2019-05-18 16:38:06.984 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.985 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.985 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe4d:a56c":set.empty{}, "172.16.10.55":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe4d:a56c":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.985 [INFO][62] daemon.go 546: No driver process to monitor
2019-05-18 16:38:06.985 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe4d:a56c":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.985 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.985 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe3b:c616":set.empty{}}}
2019-05-18 16:38:06.985 [INFO][62] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.985 [INFO][62] 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:"cmp001" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-05-18 16:38:06.986 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-05-18 16:38:06.986 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-05-18 16:38:06.986 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-05-18 16:38:06.986 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-05-18 16:38:06.986 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-05-18 16:38:06.988 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-05-18 16:38:06.989 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-05-18 16:38:06.990 [INFO][62] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-05-18 16:38:06.990 [INFO][62] watchersyncer.go 127: Sending status update Status=resync
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-05-18 16:38:06.991 [INFO][62] watchersyncer.go 127: Sending status update Status=in-sync
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 7b859c7918434ccc80d486a120b41883 6 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp001,name=DefaultEndpointToHostAction) Return 10 0s} 1}
2019-05-18 16:38:06.992 [INFO][62] config_batcher.go 102: Datamodel in sync, flushing config update
2019-05-18 16:38:06.993 [INFO][62] config_batcher.go 112: Sending config update global: map[ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:7b859c7918434ccc80d486a120b41883], host: map[DefaultEndpointToHostAction:Return].
2019-05-18 16:38:06.993 [INFO][62] async_calc_graph.go 160: First time we've been in sync
2019-05-18 16:38:06.993 [INFO][62] event_sequencer.go 210: Possible config update. global=map[string]string{"ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-05-18 16:38:06.993 [INFO][62] usagerep.go 83: Waiting before first check-in delay=5m0.028s
2019-05-18 16:38:06.993 [INFO][62] config_params.go 217: Merging in config from datastore (global): map[ClusterGUID:7b859c7918434ccc80d486a120b41883 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0]
2019-05-18 16:38:06.993 [INFO][62] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.993 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:06.994 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.994 [INFO][62] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.995 [INFO][62] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.995 [INFO][62] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.995 [INFO][62] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:06.995 [INFO][62] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:06.995 [INFO][62] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:06.996 [INFO][62] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.996 [INFO][62] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:06.996 [INFO][62] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.997 [INFO][62] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-05-18 16:38:06.997 [INFO][62] daemon.go 892: Datastore now in sync.
2019-05-18 16:38:06.997 [INFO][62] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-05-18 16:38:06.997 [INFO][62] 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:06.997 [INFO][62] 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:06.997 [INFO][62] 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:06.997 [INFO][62] 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:06.997 [INFO][62] 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:06.997 [INFO][62] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-05-18 16:38:06.997 [INFO][62] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=172.150258ms
2019-05-18 16:38:06.998 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.998 [INFO][62] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-05-18 16:38:06.998 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.999 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.000 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.000 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:07.000 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.000 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.000 [INFO][62] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-05-18 16:38:07.000 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-05-18 16:38:07.000 [INFO][62] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:07.000 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:07.000 [INFO][62] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:07.000 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:07.023 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=22.634714ms
2019-05-18 16:38:07.023 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=22.828929ms
2019-05-18 16:38:07.023 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.023 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-05-18 16:38:07.024 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-05-18 16:38:07.024 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-05-18 16:38:07.024 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.024 [INFO][62] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-05-18 16:38:07.118 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:07.119 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:07.122 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.124 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:07.129 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:07.136 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:07.141 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:07.146 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.741 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=743.435821
2019-05-18 16:38:07.741 [INFO][62] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.916099728
2019-05-18 16:38:08.876 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:08.876 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:08.877 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:08.880 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:08.881 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:08.882 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:08.883 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:08.887 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:08.888 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:08.890 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:08.892 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.060143999999998
2019-05-18 16:38:09.268 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.268 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:09.269 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:09.270 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4649099999999997
2019-05-18 16:38:09.293 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.293 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:09.295 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:09.297 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.183828
2019-05-18 16:38:09.301 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.301 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:09.303 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:09.304 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.701856
2019-05-18 16:38:09.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:09.477 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:09.478 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.277675
2019-05-18 16:38:09.514 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.514 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:09.515 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:09.516 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.287601
2019-05-18 16:38:09.671 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.672 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:09.673 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:09.674 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.849162
2019-05-18 16:38:09.694 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.694 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:09.695 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:09.697 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7812449999999997
2019-05-18 16:38:09.744 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.744 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:09.745 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:09.746 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5661159999999996
2019-05-18 16:38:11.254 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.254 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:11.256 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:11.257 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7119359999999997
2019-05-18 16:38:11.293 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.293 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:11.294 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:11.296 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6030200000000003
2019-05-18 16:38:11.300 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.300 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:11.300 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:11.301 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.797385
2019-05-18 16:38:11.475 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.475 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:11.476 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:11.478 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3291000000000004
2019-05-18 16:38:11.514 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.514 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:11.518 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:11.519 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.729513
2019-05-18 16:38:11.674 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.674 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:11.676 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:11.678 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.5576280000000002
2019-05-18 16:38:11.695 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.695 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:11.696 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:11.698 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.337676
2019-05-18 16:38:11.745 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.745 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:11.746 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:11.747 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.408324
2019-05-18 16:38:15.254 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.254 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:15.255 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:15.257 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9011810000000002
2019-05-18 16:38:15.294 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.294 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:15.295 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:15.297 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.035881
2019-05-18 16:38:15.300 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.300 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:15.301 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:15.302 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.465691
2019-05-18 16:38:15.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.477 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:15.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:15.480 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.084804
2019-05-18 16:38:15.516 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.516 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:15.517 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:15.518 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.338966
2019-05-18 16:38:15.672 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.672 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:15.673 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:15.676 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.004798
2019-05-18 16:38:15.695 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.695 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:15.697 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:15.699 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.448022
2019-05-18 16:38:15.745 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.745 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:15.747 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:15.749 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.659729
2019-05-18 16:38:17.802 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:17.802 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:17.802 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:17.802 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:17.802 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:17.804 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.46194ms
2019-05-18 16:38:17.804 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.834526ms
2019-05-18 16:38:17.804 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.264678
2019-05-18 16:38:23.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.252 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:23.254 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:23.256 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.467855
2019-05-18 16:38:23.295 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.295 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:23.296 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:23.298 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.088081
2019-05-18 16:38:23.300 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.300 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:23.301 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:23.302 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1050790000000004
2019-05-18 16:38:23.475 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:23.477 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:23.478 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.396388
2019-05-18 16:38:23.514 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.514 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:23.515 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:23.517 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.597691
2019-05-18 16:38:23.672 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.672 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:23.673 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:23.675 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.142882
2019-05-18 16:38:23.694 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.694 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:23.695 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:23.697 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.667411
2019-05-18 16:38:23.744 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.744 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:23.745 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:23.747 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.806637
2019-05-18 16:38:28.543 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:28.544 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:28.544 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:28.544 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:28.544 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:28.546 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.782207ms
2019-05-18 16:38:28.547 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.719595ms
2019-05-18 16:38:28.548 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.074109
2019-05-18 16:38:38.861 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:38.861 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:38.861 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:38.861 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:38.861 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:38.863 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.561451ms
2019-05-18 16:38:38.863 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.777251ms
2019-05-18 16:38:38.863 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.178079
2019-05-18 16:38:39.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.252 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:39.254 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:39.257 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.806010000000001
2019-05-18 16:38:39.295 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.296 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:39.298 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:39.302 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.0061610000000005
2019-05-18 16:38:39.303 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.303 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:39.304 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:39.306 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.782575
2019-05-18 16:38:39.476 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.476 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:39.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:39.480 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.437571
2019-05-18 16:38:39.515 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.515 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:39.517 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:39.518 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2123049999999997
2019-05-18 16:38:39.672 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.673 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:39.674 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:39.676 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.149363
2019-05-18 16:38:39.694 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.695 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:39.698 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:39.701 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.524552
2019-05-18 16:38:39.748 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.748 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:39.749 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:39.751 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.500308
2019-05-18 16:38:49.040 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:49.040 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:49.040 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:49.040 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:49.040 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:49.042 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.275712ms
2019-05-18 16:38:49.042 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.924977ms
2019-05-18 16:38:49.042 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.298349
2019-05-18 16:38:59.972 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:59.972 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:59.972 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:59.972 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:59.972 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:59.974 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.268864ms
2019-05-18 16:38:59.974 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.494018ms
2019-05-18 16:38:59.974 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.8742940000000001
2019-05-18 16:39:10.810 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:10.810 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:10.810 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:10.810 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:10.810 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:10.811 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.289747ms
2019-05-18 16:39:10.811 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.046799ms
2019-05-18 16:39:10.811 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.641076
2019-05-18 16:39:11.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.252 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:39:11.253 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:39:11.259 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.699552
2019-05-18 16:39:11.297 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.297 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:39:11.297 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:39:11.298 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:39:11.299 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:39:11.301 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9366649999999996
2019-05-18 16:39:11.477 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.477 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:11.478 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:11.479 [WARNING][62] 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.480 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1231940000000002
2019-05-18 16:39:11.515 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.515 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:39:11.517 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:39:11.519 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.595289
2019-05-18 16:39:11.673 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.673 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:39:11.674 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:39:11.675 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3145800000000003
2019-05-18 16:39:11.693 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.694 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:11.695 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:11.697 [WARNING][62] 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.697 [WARNING][62] 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.698 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.6529739999999995
2019-05-18 16:39:11.745 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.746 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:39:11.747 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:39:11.748 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9151580000000004
2019-05-18 16:39:12.483 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.484 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:12.488 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:12.491 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.375133
2019-05-18 16:39:12.704 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.704 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:12.705 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:12.707 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.3257600000000003
2019-05-18 16:39:13.484 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.484 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:13.485 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:13.487 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.217869
2019-05-18 16:39:13.701 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.702 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:13.702 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:13.705 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.474482
2019-05-18 16:39:15.484 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.484 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:15.486 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:15.488 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.530778
2019-05-18 16:39:15.702 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.702 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:15.704 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:15.706 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.933239
2019-05-18 16:39:19.484 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.485 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:19.486 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:19.489 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.390484
2019-05-18 16:39:19.703 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.703 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:19.704 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:19.706 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.603611
2019-05-18 16:39:20.850 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:20.850 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:20.850 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:20.851 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:20.851 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:20.854 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.075917ms
2019-05-18 16:39:20.854 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.782709ms
2019-05-18 16:39:20.854 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.26008
2019-05-18 16:39:27.481 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.481 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:27.482 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:27.484 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.394658
2019-05-18 16:39:27.702 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.702 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:27.704 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:27.708 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.212027
2019-05-18 16:39:31.334 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:31.334 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:31.334 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:31.335 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:31.335 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:31.337 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.115255ms
2019-05-18 16:39:31.337 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.175568ms
2019-05-18 16:39:31.338 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.201301
2019-05-18 16:39:39.085 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:39.085 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:39:39.085 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:39:39.086 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.712882
2019-05-18 16:39:41.661 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:41.661 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:41.661 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:41.661 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:41.661 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:41.664 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.895197ms
2019-05-18 16:39:41.665 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.062283ms
2019-05-18 16:39:41.666 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.640436
2019-05-18 16:39:43.481 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.481 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:43.483 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:43.485 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.306303
2019-05-18 16:39:43.703 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.703 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:43.705 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:43.708 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.279535999999999
2019-05-18 16:39:52.119 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:52.119 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:52.119 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:52.119 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:52.119 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:52.122 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.904925ms
2019-05-18 16:39:52.122 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.058664ms
2019-05-18 16:39:52.123 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.560258
2019-05-18 16:40:02.133 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:02.133 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:02.133 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:02.133 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:02.134 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:02.135 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.128774ms
2019-05-18 16:40:02.135 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.277976ms
2019-05-18 16:40:02.135 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.772068
2019-05-18 16:40:12.973 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:12.973 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:12.973 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:12.973 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:12.973 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:12.976 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.999933ms
2019-05-18 16:40:12.976 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.294126ms
2019-05-18 16:40:12.976 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.76565
2019-05-18 16:40:15.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.252 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:40:15.253 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:40:15.256 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.625059
2019-05-18 16:40:15.294 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.294 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:15.295 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:15.297 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.932593
2019-05-18 16:40:15.300 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.300 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:40:15.301 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:40:15.302 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.7930030000000001
2019-05-18 16:40:15.482 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.482 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:15.483 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:15.486 [WARNING][62] 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.486 [WARNING][62] 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.487 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.8176190000000005
2019-05-18 16:40:15.517 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.517 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:40:15.517 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:40:15.519 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1262600000000003
2019-05-18 16:40:15.671 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.672 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:40:15.673 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:40:15.676 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.24236
2019-05-18 16:40:15.702 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.703 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:15.704 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:15.706 [WARNING][62] 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.707 [WARNING][62] 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.707 [WARNING][62] 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.708 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.94144
2019-05-18 16:40:15.747 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.747 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:40:15.749 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:40:15.751 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.746559
2019-05-18 16:40:16.491 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.492 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:16.494 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:16.497 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.725673
2019-05-18 16:40:16.714 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.714 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:16.716 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:16.719 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.321161
2019-05-18 16:40:17.493 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.493 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:17.495 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:17.497 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.035528
2019-05-18 16:40:17.712 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.712 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:17.714 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:17.718 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.263948
2019-05-18 16:40:19.492 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.493 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:19.495 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:19.497 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8756429999999997
2019-05-18 16:40:19.712 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.713 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:19.714 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:19.717 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.624828999999999
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{}}
2019-05-18 16:40:22.650 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{}}
2019-05-18 16:40:22.650 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{}}
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.10098900000000001
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 471: Linux interface state changed. ifaceName="cali8b8ac63915d" state="up"
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali8b8ac63915d", State:"up"}
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.650 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.650 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.650 [INFO][62] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.651 [INFO][62] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.651 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.651 [INFO][62] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.192/32 ifaceName="cali8b8ac63915d" ipVersion=0x4
2019-05-18 16:40:22.651 [INFO][62] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali8b8ac63915d" ipVersion=0x4
2019-05-18 16:40:22.651 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.935221
2019-05-18 16:40:22.651 [INFO][62] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.651 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.651 [INFO][62] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali8b8ac63915d", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.652 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.652 [INFO][62] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.192/32 ifaceName="cali8b8ac63915d" ipVersion=0x4
2019-05-18 16:40:22.652 [INFO][62] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali8b8ac63915d" ipVersion=0x4
2019-05-18 16:40:22.652 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.426548
2019-05-18 16:40:22.660 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-7gfsf, name=eth0)
2019-05-18 16:40:22.660 [INFO][62] 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:22.661 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.661 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:22.661 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.661 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.661 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:22.661 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.661 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-7gfsf" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali8b8ac63915d" mac:"e2:ab:6c:55:c4:6a" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-05-18 16:40:22.661 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.661 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.661 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali8b8ac63915d" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali8b8ac63915d" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.662 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.662 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.662 [INFO][62] 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-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.662 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.662 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali8b8ac63915d" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali8b8ac63915d" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.662 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.662 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.663 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:22.663 [INFO][62] 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-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.663 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:22.664 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.667 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.721 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:22.722 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"} status="up"
2019-05-18 16:40:22.722 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=60.205541000000004
2019-05-18 16:40:23.372 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.372 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:23.372 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:23.372 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:23.373 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:23.375 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.237324ms
2019-05-18 16:40:23.375 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.764248ms
2019-05-18 16:40:23.376 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.287896
2019-05-18 16:40:23.487 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.488 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:23.489 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:23.493 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.323382
2019-05-18 16:40:23.676 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.676 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:23.677 [INFO][62] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-05-18 16:40:23.678 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:23.680 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.798841
2019-05-18 16:40:23.725 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.726 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:23.728 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:23.732 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.197367
2019-05-18 16:40:24.677 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.677 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:24.680 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:24.684 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.980163999999999
2019-05-18 16:40:24.728 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.728 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:24.729 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:24.731 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.547803
2019-05-18 16:40:26.673 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:26.674 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:26.675 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:26.677 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.140716
2019-05-18 16:40:26.725 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:26.725 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:26.726 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:26.728 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.235642
2019-05-18 16:40:30.295 [INFO][62] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-7gfsf, name=eth0)
2019-05-18 16:40:30.295 [INFO][62] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-7gfsf" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali8b8ac63915d" mac:"e2:ab:6c:55:c4:6a" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-05-18 16:40:30.295 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.295 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.295 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali8b8ac63915d" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.295 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.295 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali8b8ac63915d" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.296 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.296 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:30.296 [INFO][62] 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-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.296 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.296 [INFO][62] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.296 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-tw-cali8b8ac63915d" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.296 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.296 [INFO][62] table.go 417: Queueing update of chain. chainName="cali-fw-cali8b8ac63915d" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.296 [INFO][62] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.297 [INFO][62] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali8b8ac63915d"
2019-05-18 16:40:30.297 [INFO][62] 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-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.297 [INFO][62] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"}
2019-05-18 16:40:30.300 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.302 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.303 [INFO][62] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.304 [INFO][62] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-7gfsf", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.304 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.338338
2019-05-18 16:40:30.677 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.677 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:30.679 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.681 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.483553
2019-05-18 16:40:30.725 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.725 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:30.726 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.728 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.283649
2019-05-18 16:40:31.491 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:31.491 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:31.494 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:31.495 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.533227
2019-05-18 16:40:34.189 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:34.190 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:34.190 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:34.190 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:34.190 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:34.192 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.16369ms
2019-05-18 16:40:34.193 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.223209ms
2019-05-18 16:40:34.193 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.418472
2019-05-18 16:40:38.671 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.671 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:38.673 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:38.675 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.162265
2019-05-18 16:40:38.726 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.726 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:38.730 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:38.733 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.177023999999999
2019-05-18 16:40:44.331 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:44.331 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:44.332 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:44.332 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:44.332 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:44.334 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.291085ms
2019-05-18 16:40:44.335 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.175257ms
2019-05-18 16:40:44.335 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9829139999999996
2019-05-18 16:40:47.487 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:47.488 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:47.489 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:47.492 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.473121
2019-05-18 16:40:54.675 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.676 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:54.678 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:54.682 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.123399
2019-05-18 16:40:54.728 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.728 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:54.730 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:54.734 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.855622
2019-05-18 16:40:55.220 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:55.220 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:55.220 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:55.220 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:55.221 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:55.223 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.456401ms
2019-05-18 16:40:55.223 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.972969ms
2019-05-18 16:40:55.223 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.924033
2019-05-18 16:41:06.174 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:06.174 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:06.174 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:06.174 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:06.175 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:06.177 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.768435ms
2019-05-18 16:41:06.180 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.742178ms
2019-05-18 16:41:06.180 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.008629
2019-05-18 16:41:11.461 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:11.462 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:41:11.462 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:41:11.463 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.955483
2019-05-18 16:41:16.774 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:16.774 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:16.774 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:16.774 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:16.774 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:16.776 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.197994ms
2019-05-18 16:41:16.777 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.14909ms
2019-05-18 16:41:16.777 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.622005
2019-05-18 16:41:19.487 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:19.488 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:41:19.490 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:41:19.494 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.012018
2019-05-18 16:41:26.677 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.677 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:41:26.678 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:41:26.680 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.238157
2019-05-18 16:41:26.724 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.724 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:41:26.725 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:41:26.727 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.75206
2019-05-18 16:41:27.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:27.252 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:27.252 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:27.252 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:27.252 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:27.254 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.269844ms
2019-05-18 16:41:27.254 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.941767ms
2019-05-18 16:41:27.255 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.299454
2019-05-18 16:41:37.725 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:37.725 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:37.725 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:37.725 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:37.725 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:37.727 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.538191ms
2019-05-18 16:41:37.727 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.621447ms
2019-05-18 16:41:37.729 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.602199
2019-05-18 16:41:45.255 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.256 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-05-18 16:41:45.257 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:41:45.259 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.766816
2019-05-18 16:41:45.305 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.305 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-05-18 16:41:45.307 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:41:45.309 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.221387
2019-05-18 16:41:45.522 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.522 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.524 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:41:45.526 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.40356
2019-05-18 16:41:45.678 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.678 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.680 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:41:45.682 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.237089
2019-05-18 16:41:45.754 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.754 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-05-18 16:41:45.755 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:41:45.758 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.1484879999999995
2019-05-18 16:41:48.375 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:48.375 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:48.375 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:48.375 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:48.375 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:48.376 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.180465ms
2019-05-18 16:41:48.376 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.229242ms
2019-05-18 16:41:48.376 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.525908
2019-05-18 16:41:59.135 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:59.135 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:59.135 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:59.135 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:59.135 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:59.136 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.561824ms
2019-05-18 16:41:59.136 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.600941ms
2019-05-18 16:41:59.137 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.872653
2019-05-18 16:42:09.431 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:09.431 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:09.431 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:09.431 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:09.432 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:09.433 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.864871ms
2019-05-18 16:42:09.434 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.250754ms
2019-05-18 16:42:09.434 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7165150000000002
2019-05-18 16:42:19.521 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:19.521 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:19.521 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:19.521 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:19.521 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:19.523 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.369501ms
2019-05-18 16:42:19.524 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.454849ms
2019-05-18 16:42:19.524 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.218613
2019-05-18 16:42:23.252 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.252 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:42:23.253 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:42:23.255 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.9233800000000003
2019-05-18 16:42:23.299 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.301 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:42:23.304 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:42:23.305 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.379061
2019-05-18 16:42:23.492 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.492 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:42:23.494 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:42:23.496 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.32986
2019-05-18 16:42:23.516 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.516 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:42:23.518 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:42:23.520 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.906327
2019-05-18 16:42:23.673 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.673 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:42:23.675 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:42:23.677 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.305706000000001
2019-05-18 16:42:23.745 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.746 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:42:23.747 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:42:23.748 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.778685
2019-05-18 16:42:29.727 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:29.727 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:29.727 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:29.727 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:29.727 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:29.729 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.481155ms
2019-05-18 16:42:29.729 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.359446ms
2019-05-18 16:42:29.729 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.854154
2019-05-18 16:42:30.671 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.672 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:42:30.674 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:42:30.677 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.155135
2019-05-18 16:42:30.727 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.727 [INFO][62] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:42:30.728 [INFO][62] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:42:30.731 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.449656
2019-05-18 16:42:40.369 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:40.369 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:40.369 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:40.369 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:40.369 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:40.371 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.628228ms
2019-05-18 16:42:40.371 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.717403ms
2019-05-18 16:42:40.371 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2072350000000003
2019-05-18 16:42:41.740 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:41.740 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:42:41.740 [INFO][62] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:42:41.743 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5632070000000002
2019-05-18 16:42:50.838 [INFO][62] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:50.838 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:50.838 [INFO][62] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:50.838 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:50.838 [INFO][62] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:50.839 [INFO][62] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.122526ms
2019-05-18 16:42:50.839 [INFO][62] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.283985ms
2019-05-18 16:42:50.839 [INFO][62] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.5238420000000001
