2019-05-18 16:38:06.904 [INFO][60] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp002", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"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{"felixhostname":"cmp002", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key", "etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem"}, 0x3:map[string]string{"LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None"}, 0x1:map[string]string{"CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}}, rawValues:map[string]string{"ReportingIntervalSecs":"0", "EtcdCaFile":"/var/lib/etcd/ca.pem", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "MetadataAddr":"None", "LogSeverityFile":"None", "ClusterType":"k8s,bgp", "LogFilePath":"None", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "EtcdEndpoints":"https://172.16.10.36:4001", "DefaultEndpointToHostAction":"Return", "CalicoVersion":"v3.3.2", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "FelixHostname":"cmp002", "LogSeveritySys":"None", "LogSeverityScreen":"Info"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-05-18 16:38:06.904 [INFO][60] driver.go 43: Using internal (linux) dataplane driver.
2019-05-18 16:38:06.904 [INFO][60] 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.905 [INFO][60] 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)(0xc4204f62d0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204f63c0), 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)(0xc4204f0020), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-05-18 16:38:06.905 [INFO][60] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4204f62d0), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4204f63c0), 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.905 [INFO][60] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-05-18 16:38:06.905 [INFO][60] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-05-18 16:38:06.905 [INFO][60] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-05-18 16:38:06.906 [INFO][60] 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.908 [INFO][60] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:06.908 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.909 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.911 [INFO][60] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-05-18 16:38:06.911 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.911 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-05-18 16:38:06.912 [INFO][60] int_dataplane.go 424: Registering to report health.
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.913 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.914 [INFO][60] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-05-18 16:38:06.914 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-05-18 16:38:06.914 [INFO][60] daemon.go 299: Connect to the dataplane driver.
2019-05-18 16:38:06.915 [INFO][60] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4201c2000), (*watchersyncer.watcherCache)(0xc4201c2080), (*watchersyncer.watcherCache)(0xc4201c2100), (*watchersyncer.watcherCache)(0xc4201c2180), (*watchersyncer.watcherCache)(0xc4201c2200), (*watchersyncer.watcherCache)(0xc4201c2280), (*watchersyncer.watcherCache)(0xc4201c2300), (*watchersyncer.watcherCache)(0xc4201c2580), (*watchersyncer.watcherCache)(0xc4201c2600), (*watchersyncer.watcherCache)(0xc4201c2680)}, results:(chan interface {})(0xc42067c600), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42000c1a8), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-05-18 16:38:06.915 [INFO][60] int_dataplane.go 981: Started internal status report thread
2019-05-18 16:38:06.915 [INFO][60] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-05-18 16:38:06.915 [INFO][60] int_dataplane.go 983: Process status reports disabled
2019-05-18 16:38:06.915 [INFO][60] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp002
2019-05-18 16:38:06.915 [INFO][60] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:06.915 [INFO][60] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-05-18 16:38:06.915 [INFO][60] iface_monitor.go 88: Interface monitoring thread started.
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] iface_monitor.go 95: Subscribed to netlink updates.
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.915 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.916 [INFO][60] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-05-18 16:38:06.916 [INFO][60] daemon.go 439: Starting the datastore Syncer
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-05-18 16:38:06.916 [INFO][60] watchersyncer.go 89: Start called
2019-05-18 16:38:06.916 [INFO][60] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-05-18 16:38:06.916 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe85:a948":set.empty{}} ifaceName="ens3"
2019-05-18 16:38:06.917 [INFO][60] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-05-18 16:38:06.917 [INFO][60] daemon.go 454: Started the processing graph
2019-05-18 16:38:06.917 [INFO][60] 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.917 [INFO][60] watchersyncer.go 147: Starting main event processing loop
2019-05-18 16:38:06.917 [INFO][60] async_calc_graph.go 134: AsyncCalcGraph running
2019-05-18 16:38:06.917 [INFO][60] daemon.go 813: Reading from dataplane driver pipe...
2019-05-18 16:38:06.917 [INFO][60] 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.917 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-05-18 16:38:06.917 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.917 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fef8:3d7b":set.empty{}} ifaceName="ens4"
2019-05-18 16:38:06.917 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-05-18 16:38:06.917 [INFO][60] 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.917 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.918 [INFO][60] daemon.go 546: No driver process to monitor
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}} ifaceName="ens5"
2019-05-18 16:38:06.918 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe85:a948":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.37":set.empty{}, "fe80::5054:ff:fe85:a948":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-05-18 16:38:06.919 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe85:a948":set.empty{}, "192.168.11.37":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fef8:3d7b":set.empty{}} ifaceName="br-mgmt"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-05-18 16:38:06.919 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}} ifaceName="ens5.1000"
2019-05-18 16:38:06.919 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.919 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.919 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.920 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.920 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.920 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-05-18 16:38:06.920 [INFO][60] watchersyncer.go 127: Sending status update Status=resync
2019-05-18 16:38:06.920 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.920 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.920 [INFO][60] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 7b859c7918434ccc80d486a120b41883 6 0s} 1}
2019-05-18 16:38:06.920 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.920 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.56":set.empty{}, "fe80::5054:ff:fef8:3d7b":set.empty{}}}
2019-05-18 16:38:06.920 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.921 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.921 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.921 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-05-18 16:38:06.921 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.921 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.921 [INFO][60] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-05-18 16:38:06.922 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe5d:b29b":set.empty{}}}
2019-05-18 16:38:06.922 [INFO][60] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-05-18 16:38:06.922 [INFO][60] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp002,name=DefaultEndpointToHostAction) Return 8 0s} 1}
2019-05-18 16:38:06.922 [INFO][60] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-05-18 16:38:06.922 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-05-18 16:38:06.922 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-05-18 16:38:06.922 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-05-18 16:38:06.922 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-05-18 16:38:06.922 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-05-18 16:38:06.922 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-05-18 16:38:06.922 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-05-18 16:38:06.922 [INFO][60] 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:"cmp002" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-05-18 16:38:06.922 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-05-18 16:38:06.922 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.922 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.923 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.923 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.923 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-05-18 16:38:06.923 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.924 [INFO][60] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-05-18 16:38:06.924 [INFO][60] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-05-18 16:38:06.924 [INFO][60] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-05-18 16:38:06.924 [INFO][60] watchersyncer.go 127: Sending status update Status=in-sync
2019-05-18 16:38:06.925 [INFO][60] config_batcher.go 102: Datamodel in sync, flushing config update
2019-05-18 16:38:06.925 [INFO][60] config_batcher.go 112: Sending config update global: map[ClusterGUID:7b859c7918434ccc80d486a120b41883 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[DefaultEndpointToHostAction:Return].
2019-05-18 16:38:06.925 [INFO][60] async_calc_graph.go 160: First time we've been in sync
2019-05-18 16:38:06.925 [INFO][60] event_sequencer.go 210: Possible config update. global=map[string]string{"LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"7b859c7918434ccc80d486a120b41883", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-05-18 16:38:06.925 [INFO][60] config_params.go 217: Merging in config from datastore (global): map[ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:7b859c7918434ccc80d486a120b41883]
2019-05-18 16:38:06.925 [INFO][60] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.925 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:06.925 [INFO][60] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.925 [INFO][60] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:06.926 [INFO][60] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:06.926 [INFO][60] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] usagerep.go 83: Waiting before first check-in delay=5m2.627s
2019-05-18 16:38:06.927 [INFO][60] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.927 [INFO][60] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-05-18 16:38:06.927 [INFO][60] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.927 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-05-18 16:38:06.928 [INFO][60] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-05-18 16:38:06.928 [INFO][60] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 302: Parsing value for FelixHostname: cmp002 (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 338: Parsed value for FelixHostname: cmp002 (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-05-18 16:38:06.928 [INFO][60] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-05-18 16:38:06.928 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.930 [INFO][60] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-05-18 16:38:06.930 [INFO][60] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 302: Parsing value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 338: Parsed value for ClusterGUID: 7b859c7918434ccc80d486a120b41883 (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-05-18 16:38:06.931 [INFO][60] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-05-18 16:38:06.931 [INFO][60] daemon.go 892: Datastore now in sync.
2019-05-18 16:38:06.931 [INFO][60] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-05-18 16:38:06.931 [INFO][60] 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.931 [INFO][60] 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.931 [INFO][60] 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.931 [INFO][60] 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.931 [INFO][60] 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.931 [INFO][60] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-05-18 16:38:06.931 [INFO][60] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=160.68626ms
2019-05-18 16:38:06.932 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.932 [INFO][60] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.932 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-05-18 16:38:06.933 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-05-18 16:38:06.936 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.936 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-05-18 16:38:06.936 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.936 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.936 [INFO][60] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-05-18 16:38:06.936 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-05-18 16:38:06.936 [INFO][60] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:06.937 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:06.937 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:06.937 [INFO][60] route_table.go 199: Trying to connect to netlink
2019-05-18 16:38:07.002 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=65.280758ms
2019-05-18 16:38:07.002 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=65.64203ms
2019-05-18 16:38:07.003 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.004 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-05-18 16:38:07.004 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-05-18 16:38:07.004 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-05-18 16:38:07.005 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-05-18 16:38:07.005 [INFO][60] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-05-18 16:38:07.177 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:07.178 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:07.180 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:07.181 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:07.182 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:07.186 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:07.195 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:07.196 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:07.752 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=820.544122
2019-05-18 16:38:07.752 [INFO][60] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.981410501
2019-05-18 16:38:08.851 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:08.851 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:08.852 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:08.853 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:08.854 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:08.857 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:08.858 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:08.859 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:08.860 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:08.863 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:08.863 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:08.867 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=16.060836
2019-05-18 16:38:09.289 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.289 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:09.289 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:09.293 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:09.295 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:09.297 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.421021
2019-05-18 16:38:09.327 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.327 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:09.328 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:09.329 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4087330000000002
2019-05-18 16:38:09.333 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.333 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:09.334 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:09.335 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.569058
2019-05-18 16:38:09.381 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.381 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:09.382 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:09.384 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.031087
2019-05-18 16:38:09.547 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.547 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:09.548 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:09.550 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.295465
2019-05-18 16:38:09.586 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.586 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:09.587 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:09.588 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.410727
2019-05-18 16:38:09.754 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:09.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:09.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:09.757 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8999479999999997
2019-05-18 16:38:11.276 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.276 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:11.277 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:11.279 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.430444
2019-05-18 16:38:11.288 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.288 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:11.289 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:11.290 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.120109
2019-05-18 16:38:11.322 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.322 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:11.323 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:11.325 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.715581
2019-05-18 16:38:11.334 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.334 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:11.335 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:11.336 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2485809999999997
2019-05-18 16:38:11.380 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.381 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:11.382 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:11.383 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.573289
2019-05-18 16:38:11.547 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.547 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:11.548 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:11.550 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.946858
2019-05-18 16:38:11.586 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.586 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:11.587 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:11.588 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.369421
2019-05-18 16:38:11.755 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:11.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:11.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:11.758 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.141539
2019-05-18 16:38:15.277 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.277 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:15.279 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:15.283 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.915115999999999
2019-05-18 16:38:15.291 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.292 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:15.293 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:15.294 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.529585
2019-05-18 16:38:15.322 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.322 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:15.323 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:15.325 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1533860000000002
2019-05-18 16:38:15.333 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.334 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:15.335 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:15.337 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.036767
2019-05-18 16:38:15.381 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.381 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:15.383 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:15.385 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.702495
2019-05-18 16:38:15.548 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.548 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:15.550 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:15.552 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.704941
2019-05-18 16:38:15.586 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.587 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:15.588 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:15.590 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.314385
2019-05-18 16:38:15.755 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:15.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:15.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:15.758 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0193350000000003
2019-05-18 16:38:17.345 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:17.345 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:17.345 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:17.345 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:17.346 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:17.347 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.689083ms
2019-05-18 16:38:17.348 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.865989ms
2019-05-18 16:38:17.348 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.361962
2019-05-18 16:38:23.274 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.274 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:23.275 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:23.277 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.816519
2019-05-18 16:38:23.289 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.289 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:23.291 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:23.292 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.358205
2019-05-18 16:38:23.322 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.322 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:23.323 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:23.324 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.605883
2019-05-18 16:38:23.333 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.333 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:23.335 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:23.337 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.4251059999999995
2019-05-18 16:38:23.383 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.383 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:23.384 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:23.385 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.220095
2019-05-18 16:38:23.546 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.547 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:23.547 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:23.549 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1715
2019-05-18 16:38:23.585 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.585 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:23.586 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:23.588 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.570664
2019-05-18 16:38:23.755 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:23.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:23.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:23.758 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.984901
2019-05-18 16:38:27.593 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:27.593 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:27.593 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:27.593 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:27.593 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:27.594 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.303115ms
2019-05-18 16:38:27.595 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.452962ms
2019-05-18 16:38:27.595 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.6982760000000001
2019-05-18 16:38:38.129 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:38.129 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:38.129 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:38.129 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:38.129 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:38.130 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.081345ms
2019-05-18 16:38:38.130 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.050209ms
2019-05-18 16:38:38.131 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.818043
2019-05-18 16:38:39.273 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.274 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:38:39.275 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:38:39.278 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.567714
2019-05-18 16:38:39.290 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.290 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:38:39.291 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:38:39.292 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.0807949999999997
2019-05-18 16:38:39.322 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.322 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:38:39.323 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:38:39.325 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.355492
2019-05-18 16:38:39.334 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.334 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:38:39.335 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:38:39.337 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.34033
2019-05-18 16:38:39.382 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.382 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:38:39.383 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:38:39.385 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.061927
2019-05-18 16:38:39.547 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.547 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:38:39.549 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:38:39.550 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.99492
2019-05-18 16:38:39.586 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.586 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:38:39.587 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:38:39.589 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6760099999999998
2019-05-18 16:38:39.755 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:39.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:38:39.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:38:39.758 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.3507540000000002
2019-05-18 16:38:48.506 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:48.506 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:48.506 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:48.506 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:48.507 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:48.509 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.244024ms
2019-05-18 16:38:48.509 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.291226ms
2019-05-18 16:38:48.509 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6423829999999997
2019-05-18 16:38:58.570 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:38:58.570 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:38:58.570 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:38:58.570 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:38:58.570 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:38:58.572 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.783039ms
2019-05-18 16:38:58.572 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.870762ms
2019-05-18 16:38:58.572 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.096437
2019-05-18 16:39:08.792 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:08.792 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:08.792 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:08.792 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:08.792 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:08.793 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.033182ms
2019-05-18 16:39:08.793 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.198421ms
2019-05-18 16:39:08.793 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.493761
2019-05-18 16:39:11.274 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.274 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:39:11.276 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:39:11.279 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.449012
2019-05-18 16:39:11.291 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.291 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:39:11.293 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:39:11.295 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.451024
2019-05-18 16:39:11.323 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.323 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:39:11.325 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:39:11.330 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.239138
2019-05-18 16:39:11.338 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.338 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:11.339 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:11.341 [WARNING][60] 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.341 [WARNING][60] 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.342 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.650949
2019-05-18 16:39:11.383 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.383 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:39:11.385 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:39:11.389 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.047404
2019-05-18 16:39:11.550 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.551 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:11.553 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:11.555 [WARNING][60] 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.557 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.0417179999999995
2019-05-18 16:39:11.590 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.590 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:39:11.594 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:39:11.596 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.161017999999999
2019-05-18 16:39:11.758 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:11.759 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:39:11.760 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:39:11.763 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.650119
2019-05-18 16:39:12.347 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.347 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:12.349 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:12.351 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.353728
2019-05-18 16:39:12.562 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:12.562 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:12.564 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:12.567 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.71767
2019-05-18 16:39:13.347 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.347 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:13.349 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:13.352 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.885161
2019-05-18 16:39:13.562 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:13.563 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:13.564 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:13.566 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.519833
2019-05-18 16:39:15.346 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.346 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:15.348 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:15.351 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.025247
2019-05-18 16:39:15.562 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:15.563 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:15.564 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:15.566 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1033
2019-05-18 16:39:19.266 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.266 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:19.267 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:19.267 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:19.267 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:19.269 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.205761ms
2019-05-18 16:39:19.269 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.47125ms
2019-05-18 16:39:19.269 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.990974
2019-05-18 16:39:19.343 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.344 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:19.347 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:19.349 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.689842
2019-05-18 16:39:19.563 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:19.563 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:19.565 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:19.567 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.621411
2019-05-18 16:39:27.347 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.347 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:27.349 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:27.351 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.17047
2019-05-18 16:39:27.562 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:27.562 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:27.565 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:27.567 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.731986
2019-05-18 16:39:30.178 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:30.178 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:30.178 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:30.178 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:30.178 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:30.179 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.02845ms
2019-05-18 16:39:30.179 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.292949ms
2019-05-18 16:39:30.180 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.54168
2019-05-18 16:39:38.488 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:38.488 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:39:38.488 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:39:38.489 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.675977
2019-05-18 16:39:40.581 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:40.581 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:40.581 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:40.581 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:40.581 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:40.582 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.097467ms
2019-05-18 16:39:40.583 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.372982ms
2019-05-18 16:39:40.583 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.6602940000000002
2019-05-18 16:39:43.343 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.343 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:39:43.345 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:39:43.347 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.082281
2019-05-18 16:39:43.562 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:43.562 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:39:43.563 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:39:43.565 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.332418
2019-05-18 16:39:50.838 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:39:50.838 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:39:50.838 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:39:50.839 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:39:50.839 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:39:50.840 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=988.484µs
2019-05-18 16:39:50.840 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.501952ms
2019-05-18 16:39:50.840 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.938149
2019-05-18 16:40:01.053 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:01.053 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:01.053 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:01.053 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:01.053 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:01.055 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.789488ms
2019-05-18 16:40:01.055 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.66282ms
2019-05-18 16:40:01.055 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.381871
2019-05-18 16:40:11.829 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:11.829 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:11.829 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:11.829 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:11.829 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:11.831 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.785919ms
2019-05-18 16:40:11.832 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.368646ms
2019-05-18 16:40:11.832 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.872677
2019-05-18 16:40:15.274 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.274 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:40:15.275 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:40:15.283 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.577341
2019-05-18 16:40:15.289 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.289 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:40:15.290 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:40:15.292 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6121469999999998
2019-05-18 16:40:15.322 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.322 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:15.323 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:15.325 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4101
2019-05-18 16:40:15.345 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.345 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:15.346 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:15.347 [WARNING][60] 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.347 [WARNING][60] 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.347 [WARNING][60] 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.349 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.981017
2019-05-18 16:40:15.382 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.382 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:40:15.383 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:40:15.386 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.480776
2019-05-18 16:40:15.561 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.561 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:15.562 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:15.568 [WARNING][60] 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.568 [WARNING][60] 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.569 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.408878999999999
2019-05-18 16:40:15.591 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.591 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:40:15.592 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:40:15.593 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.2714570000000003
2019-05-18 16:40:15.754 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:15.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:40:15.756 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:40:15.758 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.00818
2019-05-18 16:40:16.352 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.352 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:16.354 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:16.357 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.670673
2019-05-18 16:40:16.574 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:16.574 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:16.575 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:16.577 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.479753
2019-05-18 16:40:17.351 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.352 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:17.353 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:17.357 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.248624
2019-05-18 16:40:17.575 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:17.575 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:17.576 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:17.578 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.950237
2019-05-18 16:40:19.352 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.352 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:19.353 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:19.354 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.586067
2019-05-18 16:40:19.572 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:19.572 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:19.574 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:19.577 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.550028
2019-05-18 16:40:22.680 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.680 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:22.680 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:22.680 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:22.681 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:22.681 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.681 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="cali4d89da15a19" state="up"
2019-05-18 16:40:22.682 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.155068ms
2019-05-18 16:40:22.682 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.683 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.243268ms
2019-05-18 16:40:22.683 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.592161
2019-05-18 16:40:22.683 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{}}
2019-05-18 16:40:22.683 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{}}
2019-05-18 16:40:22.683 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{}}
2019-05-18 16:40:22.683 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.683 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.683 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"cali4d89da15a19", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.683 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.684 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.10926699999999999
2019-05-18 16:40:22.684 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"cali4d89da15a19", State:"up"}
2019-05-18 16:40:22.684 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.684 [INFO][60] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.684 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.684 [INFO][60] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.684 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.685 [INFO][60] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.64/32 ifaceName="cali4d89da15a19" ipVersion=0x4
2019-05-18 16:40:22.685 [INFO][60] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="cali4d89da15a19" ipVersion=0x4
2019-05-18 16:40:22.685 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.244182
2019-05-18 16:40:22.701 [INFO][60] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-strkg, name=eth0)
2019-05-18 16:40:22.702 [INFO][60] 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.702 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.702 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:22.702 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.702 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.702 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:22.702 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.703 [INFO][60] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-strkg" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali4d89da15a19" mac:"3e:9a:7b:fa:f3:ed" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-05-18 16:40:22.703 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.703 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-cali4d89da15a19" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-cali4d89da15a19" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.703 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.703 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.703 [INFO][60] 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-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.703 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.703 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-cali4d89da15a19" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.703 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-cali4d89da15a19" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.704 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.704 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.704 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.704 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:22.704 [INFO][60] 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-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.704 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:22.705 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.709 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.765 [INFO][60] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-05-18 16:40:22.765 [INFO][60] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"} status="up"
2019-05-18 16:40:22.765 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=61.973474
2019-05-18 16:40:22.876 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="caliad4093086f6"
2019-05-18 16:40:22.876 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{}}
2019-05-18 16:40:22.876 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{}}
2019-05-18 16:40:22.877 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{}}
2019-05-18 16:40:22.877 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.877 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.194532
2019-05-18 16:40:22.878 [INFO][60] int_dataplane.go 471: Linux interface state changed. ifaceName="caliad4093086f6" state="up"
2019-05-18 16:40:22.879 [INFO][60] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"caliad4093086f6", State:"up"}
2019-05-18 16:40:22.879 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.879 [INFO][60] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.879 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.879 [INFO][60] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="caliad4093086f6"
2019-05-18 16:40:22.879 [INFO][60] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.879 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.880 [INFO][60] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="caliad4093086f6" ipVersion=0x4
2019-05-18 16:40:22.880 [INFO][60] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="caliad4093086f6" ipVersion=0x4
2019-05-18 16:40:22.880 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.09443
2019-05-18 16:40:22.880 [INFO][60] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.880 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.880 [INFO][60] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"caliad4093086f6", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-05-18 16:40:22.880 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.881 [INFO][60] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.112.65/32 ifaceName="caliad4093086f6" ipVersion=0x4
2019-05-18 16:40:22.881 [INFO][60] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="caliad4093086f6" ipVersion=0x4
2019-05-18 16:40:22.881 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.552953
2019-05-18 16:40:22.883 [INFO][60] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-j2drj, name=eth0)
2019-05-18 16:40:22.883 [INFO][60] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-j2drj" endpoint_id:"eth0" > endpoint:<state:"active" name:"caliad4093086f6" mac:"9e:50:9f:8a:63:24" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-05-18 16:40:22.883 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:22.883 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-caliad4093086f6" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-caliad4093086f6" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.884 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-05-18 16:40:22.884 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.884 [INFO][60] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-caliad4093086f6" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-caliad4093086f6" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.884 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.884 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-05-18 16:40:22.885 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:22.885 [INFO][60] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.885 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:22.886 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:22.891 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:22.946 [INFO][60] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:22.946 [INFO][60] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"} status="up"
2019-05-18 16:40:22.946 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=62.928490000000004
2019-05-18 16:40:23.631 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.632 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:23.633 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:23.637 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.037216
2019-05-18 16:40:23.776 [INFO][60] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-05-18 16:40:23.902 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.902 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:23.904 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:23.909 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.526154999999999
2019-05-18 16:40:23.953 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:23.954 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:23.958 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:23.960 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.489357
2019-05-18 16:40:24.480 [INFO][60] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=9
2019-05-18 16:40:24.902 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.903 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:24.904 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:24.908 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.884469
2019-05-18 16:40:24.952 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:24.952 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:24.954 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:24.956 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.1678749999999996
2019-05-18 16:40:26.900 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:26.901 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:26.903 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:26.910 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.142602
2019-05-18 16:40:26.955 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:26.955 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:26.957 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:26.960 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.1116850000000005
2019-05-18 16:40:30.197 [INFO][60] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=kube-system/coredns-7f8f94c97b-j2drj, name=eth0)
2019-05-18 16:40:30.197 [INFO][60] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"kube-system/coredns-7f8f94c97b-j2drj" endpoint_id:"eth0" > endpoint:<state:"active" name:"caliad4093086f6" mac:"9e:50:9f:8a:63:24" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.65/32" > 
2019-05-18 16:40:30.197 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.197 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.197 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-caliad4093086f6" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.197 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.197 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-caliad4093086f6" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.198 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.198 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-caliad4093086f6" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.198 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.198 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-caliad4093086f6" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.198 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="caliad4093086f6"
2019-05-18 16:40:30.199 [INFO][60] endpoint_mgr.go 350: Re-evaluated workload endpoint status adminUp=true failed=false known=true operUp=true status="up" workloadEndpointID=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.199 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"}
2019-05-18 16:40:30.200 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.203 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.206 [INFO][60] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.206 [INFO][60] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"kube-system/coredns-7f8f94c97b-j2drj", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.206 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.385564
2019-05-18 16:40:30.393 [INFO][60] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp002, orchestrator=k8s, workload=netchecker/netchecker-agent-strkg, name=eth0)
2019-05-18 16:40:30.394 [INFO][60] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-strkg" endpoint_id:"eth0" > endpoint:<state:"active" name:"cali4d89da15a19" mac:"3e:9a:7b:fa:f3:ed" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.112.64/32" > 
2019-05-18 16:40:30.394 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.394 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.395 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-cali4d89da15a19" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.395 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-05-18 16:40:30.395 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-cali4d89da15a19" ipVersion=0x4 table="filter"
2019-05-18 16:40:30.395 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.395 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:30.396 [INFO][60] 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-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.396 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.396 [INFO][60] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.396 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-tw-cali4d89da15a19" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.396 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-05-18 16:40:30.396 [INFO][60] table.go 417: Queueing update of chain. chainName="cali-fw-cali4d89da15a19" ipVersion=0x6 table="filter"
2019-05-18 16:40:30.396 [INFO][60] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.397 [INFO][60] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="cali4d89da15a19"
2019-05-18 16:40:30.397 [INFO][60] 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-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.397 [INFO][60] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"}
2019-05-18 16:40:30.400 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.401 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.404 [INFO][60] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-05-18 16:40:30.404 [INFO][60] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-strkg", EndpointId:"eth0"} status="up"
2019-05-18 16:40:30.404 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.459342000000001
2019-05-18 16:40:30.901 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.902 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:30.903 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:30.907 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.232989000000001
2019-05-18 16:40:30.951 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:30.952 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:30.954 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:30.957 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.0245869999999995
2019-05-18 16:40:31.574 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:31.575 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:31.577 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:31.580 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.504949
2019-05-18 16:40:32.930 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:32.930 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:32.930 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:32.930 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:32.931 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:32.932 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.288167ms
2019-05-18 16:40:32.932 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.11729ms
2019-05-18 16:40:32.932 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.667665
2019-05-18 16:40:38.896 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.896 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:38.898 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:38.902 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.675278
2019-05-18 16:40:38.952 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:38.952 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:38.954 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:38.957 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.068913
2019-05-18 16:40:43.748 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:43.748 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:43.748 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:43.748 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:43.748 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:43.751 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.607081ms
2019-05-18 16:40:43.751 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.123717ms
2019-05-18 16:40:43.752 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.809438
2019-05-18 16:40:47.570 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:47.570 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:40:47.572 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:40:47.575 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.30699
2019-05-18 16:40:54.021 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.021 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:40:54.021 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:40:54.021 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:40:54.021 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:40:54.023 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.259949ms
2019-05-18 16:40:54.024 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.397644ms
2019-05-18 16:40:54.025 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.103384
2019-05-18 16:40:54.896 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.896 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:40:54.898 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:40:54.901 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.1264259999999995
2019-05-18 16:40:54.951 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:40:54.952 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:40:54.956 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:40:54.959 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.626962
2019-05-18 16:41:04.817 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:04.818 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:04.818 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:04.818 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:04.818 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:04.820 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.205334ms
2019-05-18 16:41:04.821 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.788577ms
2019-05-18 16:41:04.821 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.626882
2019-05-18 16:41:14.487 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:14.487 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:41:14.487 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:41:14.491 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.735008
2019-05-18 16:41:15.096 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:15.096 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:15.096 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:15.096 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:15.096 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:15.099 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.307368ms
2019-05-18 16:41:15.099 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.705449ms
2019-05-18 16:41:15.099 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.179504
2019-05-18 16:41:19.570 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:19.570 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:41:19.571 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:41:19.573 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.477151
2019-05-18 16:41:25.201 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:25.201 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:25.201 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:25.201 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:25.202 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:25.203 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.480163ms
2019-05-18 16:41:25.204 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.270845ms
2019-05-18 16:41:25.204 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.24542
2019-05-18 16:41:26.896 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.896 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:41:26.898 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:41:26.902 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.361233
2019-05-18 16:41:26.951 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:26.951 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:41:26.952 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:41:26.954 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.547757
2019-05-18 16:41:35.959 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:35.959 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:35.959 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:35.960 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:35.959 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:35.962 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.745903ms
2019-05-18 16:41:35.962 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.62094ms
2019-05-18 16:41:35.962 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.998136
2019-05-18 16:41:45.275 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.276 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-05-18 16:41:45.279 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:41:45.282 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.183553
2019-05-18 16:41:45.297 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.297 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-05-18 16:41:45.298 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:41:45.299 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.461896
2019-05-18 16:41:45.386 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.386 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-05-18 16:41:45.387 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:41:45.390 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.024764
2019-05-18 16:41:45.596 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.597 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.598 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:41:45.602 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.170139
2019-05-18 16:41:45.761 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:45.761 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-05-18 16:41:45.763 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:41:45.766 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.868267
2019-05-18 16:41:46.387 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:46.387 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:46.387 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:46.388 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:46.388 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:46.390 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.177683ms
2019-05-18 16:41:46.390 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.408499ms
2019-05-18 16:41:46.391 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.589442
2019-05-18 16:41:56.444 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:41:56.444 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:41:56.444 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:41:56.444 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:41:56.444 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:41:56.445 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.073409ms
2019-05-18 16:41:56.446 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.63593ms
2019-05-18 16:41:56.446 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.907476
2019-05-18 16:42:06.740 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:06.740 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:06.740 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:06.740 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:06.741 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:06.742 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.823166ms
2019-05-18 16:42:06.743 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.129235ms
2019-05-18 16:42:06.743 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.05067
2019-05-18 16:42:16.760 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:16.761 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:16.761 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:16.761 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:16.761 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:16.763 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.32634ms
2019-05-18 16:42:16.763 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.600846ms
2019-05-18 16:42:16.764 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.34323
2019-05-18 16:42:23.274 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.274 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-05-18 16:42:23.275 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-05-18 16:42:23.278 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.661546
2019-05-18 16:42:23.289 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.289 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-05-18 16:42:23.291 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-05-18 16:42:23.292 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.199156
2019-05-18 16:42:23.381 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.381 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-05-18 16:42:23.383 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-05-18 16:42:23.385 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.753851
2019-05-18 16:42:23.573 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.573 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-05-18 16:42:23.575 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-05-18 16:42:23.577 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.915242
2019-05-18 16:42:23.587 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.587 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-05-18 16:42:23.588 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-05-18 16:42:23.590 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.145831
2019-05-18 16:42:23.755 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:23.755 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-05-18 16:42:23.757 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-05-18 16:42:23.759 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.595265
2019-05-18 16:42:27.146 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:27.146 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:27.146 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:27.146 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:27.147 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:27.148 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.304205ms
2019-05-18 16:42:27.148 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.679604ms
2019-05-18 16:42:27.148 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.9784899999999999
2019-05-18 16:42:30.896 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.897 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-05-18 16:42:30.898 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-05-18 16:42:30.901 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.500859999999999
2019-05-18 16:42:30.950 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:30.950 [INFO][60] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-05-18 16:42:30.951 [INFO][60] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-05-18 16:42:30.954 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.167166
2019-05-18 16:42:38.076 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:38.076 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:38.076 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:38.076 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:38.076 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:38.078 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.135728ms
2019-05-18 16:42:38.079 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.853752ms
2019-05-18 16:42:38.080 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.748459
2019-05-18 16:42:48.664 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:48.664 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-05-18 16:42:48.664 [INFO][60] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-05-18 16:42:48.664 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-05-18 16:42:48.664 [INFO][60] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-05-18 16:42:48.666 [INFO][60] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.750548ms
2019-05-18 16:42:48.666 [INFO][60] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.923478ms
2019-05-18 16:42:48.666 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5281190000000002
2019-05-18 16:42:49.362 [INFO][60] int_dataplane.go 751: Applying dataplane updates
2019-05-18 16:42:49.362 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-05-18 16:42:49.363 [INFO][60] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-05-18 16:42:49.366 [INFO][60] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.553979
