2019-10-26 13:59:21.482 [INFO][66] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=6 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"cmp001", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"77e3fde152bc47f88c962d00f5907118", ClusterType:"k8s,bgp", CalicoVersion:"v3.3.2", ExternalNodesCIDRList:[]string(nil), DebugMemoryProfilePath:"", DebugCPUProfilePath:"/tmp/felix-cpu-<timestamp>.pprof", DebugDisableLogDropping:false, DebugSimulateCalcGraphHangAfter:0, DebugSimulateDataplaneHangAfter:0, sourceToRawConfig:map[config.Source]map[string]string{0x1:map[string]string{"LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}, 0x4:map[string]string{"etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"cmp001", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key"}, 0x3:map[string]string{"LogSeverityFile":"None", "LogSeveritySys":"None", "MetadataAddr":"None", "LogFilePath":"None"}}, rawValues:map[string]string{"EtcdEndpoints":"https://172.16.10.36:4001", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "ReportingIntervalSecs":"0", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "MetadataAddr":"None", "LogSeverityFile":"None", "FelixHostname":"cmp001", "LogSeveritySys":"None", "DefaultEndpointToHostAction":"Return", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118", "EtcdCaFile":"/var/lib/etcd/ca.pem", "LogFilePath":"None", "LogSeverityScreen":"Info"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-10-26 13:59:21.482 [INFO][66] driver.go 43: Using internal (linux) dataplane driver.
2019-10-26 13:59:21.483 [INFO][66] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-10-26 13:59:21.484 [INFO][66] 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)(0xc4200a6960), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200a6aa0), 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)(0xc4207964a0), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-10-26 13:59:21.484 [INFO][66] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc4200a6960), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc4200a6aa0), WorkloadIfacePrefixes:[]string{"cali"}, IptablesMarkAccept:0x10000, IptablesMarkPass:0x20000, IptablesMarkScratch0:0x40000, IptablesMarkScratch1:0x80000, IptablesMarkEndpoint:0xfff00000, IptablesMarkNonCaliEndpoint:0x100000, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, KubeIPVSSupportEnabled:false, OpenStackMetadataIP:net.IP(nil), OpenStackMetadataPort:0x2247, OpenStackSpecialCasesEnabled:false, IPIPEnabled:false, IPIPTunnelAddress:net.IP(nil), IptablesLogPrefix:"calico-packet", EndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, DisableConntrackInvalid:false, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}}
2019-10-26 13:59:21.484 [INFO][66] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-10-26 13:59:21.484 [INFO][66] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-10-26 13:59:21.484 [INFO][66] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-10-26 13:59:21.486 [INFO][66] feature_detect.go 108: Updating detected iptables features features=iptables.Features{SNATFullyRandom:true, MASQFullyRandom:true, RestoreSupportsLock:true} iptablesVersion=1.6.2 kernelVersion=4.15.0
2019-10-26 13:59:21.487 [INFO][66] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:21.487 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.487 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.488 [INFO][66] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-10-26 13:59:21.488 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.488 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-10-26 13:59:21.488 [INFO][66] int_dataplane.go 424: Registering to report health.
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.488 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.489 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.490 [INFO][66] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.490 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.491 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.491 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.491 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.491 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.491 [INFO][66] daemon.go 299: Connect to the dataplane driver.
2019-10-26 13:59:21.491 [INFO][66] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-10-26 13:59:21.491 [INFO][66] int_dataplane.go 981: Started internal status report thread
2019-10-26 13:59:21.491 [INFO][66] int_dataplane.go 983: Process status reports disabled
2019-10-26 13:59:21.491 [INFO][66] iface_monitor.go 88: Interface monitoring thread started.
2019-10-26 13:59:21.491 [INFO][66] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-10-26 13:59:21.491 [INFO][66] iface_monitor.go 95: Subscribed to netlink updates.
2019-10-26 13:59:21.491 [INFO][66] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-10-26 13:59:21.491 [INFO][66] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc4206b7180), (*watchersyncer.watcherCache)(0xc4206b7200), (*watchersyncer.watcherCache)(0xc4206b7280), (*watchersyncer.watcherCache)(0xc4206b7300), (*watchersyncer.watcherCache)(0xc4206b7380), (*watchersyncer.watcherCache)(0xc4206b7400), (*watchersyncer.watcherCache)(0xc4206b7480), (*watchersyncer.watcherCache)(0xc4206b7500), (*watchersyncer.watcherCache)(0xc4206b7600), (*watchersyncer.watcherCache)(0xc4206b7680)}, results:(chan interface {})(0xc420083c20), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc4203de2c0), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-10-26 13:59:21.493 [INFO][66] calc_graph.go 96: Creating calculation graph, filtered to hostname cmp001
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.493 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe2b:f846":set.empty{}} ifaceName="ens3"
2019-10-26 13:59:21.493 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-10-26 13:59:21.493 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.493 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"lo", Addrs:set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}}}
2019-10-26 13:59:21.493 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe32:6a89":set.empty{}} ifaceName="ens4"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}} ifaceName="ens5"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe32:6a89":set.empty{}} ifaceName="br-mgmt"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.494 [INFO][66] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-10-26 13:59:21.494 [INFO][66] daemon.go 439: Starting the datastore Syncer
2019-10-26 13:59:21.494 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}} ifaceName="ens5.1000"
2019-10-26 13:59:21.495 [INFO][66] watchersyncer.go 89: Start called
2019-10-26 13:59:21.495 [INFO][66] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-10-26 13:59:21.495 [INFO][66] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-10-26 13:59:21.495 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.495 [INFO][66] daemon.go 454: Started the processing graph
2019-10-26 13:59:21.495 [INFO][66] async_calc_graph.go 134: AsyncCalcGraph running
2019-10-26 13:59:21.495 [INFO][66] watchersyncer.go 147: Starting main event processing loop
2019-10-26 13:59:21.495 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe2b:f846":set.empty{}}}
2019-10-26 13:59:21.495 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe2b:f846":set.empty{}, "192.168.11.36":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.496 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.36":set.empty{}, "fe80::5054:ff:fe2b:f846":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.496 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.496 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.495 [INFO][66] daemon.go 813: Reading from dataplane driver pipe...
2019-10-26 13:59:21.496 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.496 [INFO][66] daemon.go 546: No driver process to monitor
2019-10-26 13:59:21.496 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.496 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.55":set.empty{}, "fe80::5054:ff:fe32:6a89":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fee8:ef0":set.empty{}}}
2019-10-26 13:59:21.497 [INFO][66] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-10-26 13:59:21.497 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.497 [INFO][66] watchersyncer.go 127: Sending status update Status=resync
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-10-26 13:59:21.497 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-10-26 13:59:21.498 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-10-26 13:59:21.497 [INFO][66] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"77e3fde152bc47f88c962d00f5907118" > config:<key:"ClusterType" value:"k8s,bgp" > config:<key:"DefaultEndpointToHostAction" value:"Return" > config:<key:"EtcdCaFile" value:"/var/lib/etcd/ca.pem" > config:<key:"EtcdCertFile" value:"/var/lib/etcd/etcd-client.crt" > config:<key:"EtcdEndpoints" value:"https://172.16.10.36:4001" > config:<key:"EtcdKeyFile" value:"/var/lib/etcd/etcd-client.key" > config:<key:"FelixHostname" value:"cmp001" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-10-26 13:59:21.498 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.498 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.501 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-10-26 13:59:21.501 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-10-26 13:59:21.501 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-10-26 13:59:21.502 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-10-26 13:59:21.502 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.502 [INFO][66] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-10-26 13:59:21.502 [INFO][66] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-10-26 13:59:21.502 [INFO][66] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-10-26 13:59:21.502 [INFO][66] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 77e3fde152bc47f88c962d00f5907118 6 0s} 1}
2019-10-26 13:59:21.503 [INFO][66] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-10-26 13:59:21.503 [INFO][66] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-10-26 13:59:21.503 [INFO][66] config_batcher.go 61: Host config update for this host: {{HostConfig(node=cmp001,name=DefaultEndpointToHostAction) Return 10 0s} 1}
2019-10-26 13:59:21.503 [INFO][66] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-10-26 13:59:21.503 [INFO][66] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-10-26 13:59:21.503 [INFO][66] watchersyncer.go 127: Sending status update Status=in-sync
2019-10-26 13:59:21.503 [INFO][66] config_batcher.go 102: Datamodel in sync, flushing config update
2019-10-26 13:59:21.503 [INFO][66] config_batcher.go 112: Sending config update global: map[ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0], host: map[DefaultEndpointToHostAction:Return].
2019-10-26 13:59:21.503 [INFO][66] async_calc_graph.go 160: First time we've been in sync
2019-10-26 13:59:21.503 [INFO][66] event_sequencer.go 210: Possible config update. global=map[string]string{"ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"77e3fde152bc47f88c962d00f5907118"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-10-26 13:59:21.504 [INFO][66] config_params.go 217: Merging in config from datastore (global): map[CalicoVersion:v3.3.2 LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:77e3fde152bc47f88c962d00f5907118 ClusterType:k8s,bgp]
2019-10-26 13:59:21.504 [INFO][66] usagerep.go 83: Waiting before first check-in delay=5m1.028s
2019-10-26 13:59:21.504 [INFO][66] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:21.504 [INFO][66] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.504 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:21.505 [INFO][66] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.505 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:21.505 [INFO][66] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.505 [INFO][66] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.505 [INFO][66] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:21.505 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.506 [INFO][66] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.506 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-10-26 13:59:21.506 [INFO][66] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.506 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-10-26 13:59:21.506 [INFO][66] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for FelixHostname: cmp001 (from environment variable)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for FelixHostname: cmp001 (from environment variable)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.507 [INFO][66] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-10-26 13:59:21.507 [INFO][66] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.507 [INFO][66] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 302: Parsing value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 338: Parsed value for ClusterGUID: 77e3fde152bc47f88c962d00f5907118 (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-10-26 13:59:21.508 [INFO][66] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-10-26 13:59:21.508 [INFO][66] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-10-26 13:59:21.508 [INFO][66] daemon.go 892: Datastore now in sync.
2019-10-26 13:59:21.508 [INFO][66] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-10-26 13:59:21.508 [INFO][66] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-10-26 13:59:21.508 [INFO][66] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-10-26 13:59:21.509 [INFO][66] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"192.168.0.0-16" pool:<cidr:"192.168.0.0/16" masquerade:true > 
2019-10-26 13:59:21.509 [INFO][66] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fd92:48c:bc74::-48" pool:<cidr:"fd92:48c:bc74::/48" > 
2019-10-26 13:59:21.509 [INFO][66] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-10-26 13:59:21.509 [INFO][66] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=166.018911ms
2019-10-26 13:59:21.509 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:21.509 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.509 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.510 [INFO][66] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.510 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.511 [INFO][66] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-10-26 13:59:21.511 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-10-26 13:59:21.511 [INFO][66] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:21.511 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:21.511 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:21.511 [INFO][66] route_table.go 199: Trying to connect to netlink
2019-10-26 13:59:21.569 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=58.087394ms
2019-10-26 13:59:21.569 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=58.219072ms
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-10-26 13:59:21.570 [INFO][66] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-10-26 13:59:21.742 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:21.743 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:21.744 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:21.745 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:21.746 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:21.748 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:21.749 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:21.750 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:22.296 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=787.232561
2019-10-26 13:59:22.296 [INFO][66] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.953397344
2019-10-26 13:59:23.403 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.403 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:23.404 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:23.405 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:23.406 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:23.407 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:23.409 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:23.410 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:23.411 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:23.412 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:23.413 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:23.416 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=12.209477
2019-10-26 13:59:23.860 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.860 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:23.862 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:23.865 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.871242
2019-10-26 13:59:23.872 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:23.872 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:23.876 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:23.878 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.929032
2019-10-26 13:59:24.095 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.095 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:24.096 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:24.099 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.225406
2019-10-26 13:59:24.232 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.233 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:24.233 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:24.234 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:24.235 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:24.236 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.912342
2019-10-26 13:59:24.250 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.252 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:24.253 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:24.255 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.894227
2019-10-26 13:59:24.280 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.280 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:24.281 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:24.282 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6441239999999997
2019-10-26 13:59:24.299 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:24.299 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:24.300 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:24.301 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3778509999999997
2019-10-26 13:59:25.850 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.850 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:25.853 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:25.855 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.424515
2019-10-26 13:59:25.871 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:25.871 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:25.872 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:25.873 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.0200690000000003
2019-10-26 13:59:26.091 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.091 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:26.092 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:26.093 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.683061
2019-10-26 13:59:26.231 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.231 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:26.231 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:26.232 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:26.234 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:26.235 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.412909
2019-10-26 13:59:26.250 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.250 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:26.255 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:26.256 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.015088
2019-10-26 13:59:26.283 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.283 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:26.284 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:26.285 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.295459
2019-10-26 13:59:26.298 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:26.298 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:26.299 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:26.301 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.261943
2019-10-26 13:59:29.850 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.850 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:29.851 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:29.853 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.697063
2019-10-26 13:59:29.869 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:29.869 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:29.871 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:29.872 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6863040000000002
2019-10-26 13:59:30.091 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.092 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:30.093 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:30.095 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.098323
2019-10-26 13:59:30.231 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.232 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:30.232 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:30.233 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:30.234 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:30.236 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.327488
2019-10-26 13:59:30.250 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.250 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:30.251 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:30.253 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.650691
2019-10-26 13:59:30.280 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.280 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:30.282 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:30.284 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.843844
2019-10-26 13:59:30.300 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:30.300 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:30.301 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:30.302 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.567064
2019-10-26 13:59:31.755 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:31.756 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:31.756 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:31.756 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:31.756 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:31.757 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.160253ms
2019-10-26 13:59:31.758 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.731541ms
2019-10-26 13:59:31.758 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.280093
2019-10-26 13:59:37.848 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.848 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:37.849 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:37.851 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.257613
2019-10-26 13:59:37.870 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:37.870 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:37.871 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:37.872 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.123012
2019-10-26 13:59:38.091 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.091 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:38.093 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:38.094 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4837420000000003
2019-10-26 13:59:38.232 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.232 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:38.232 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:38.233 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:38.235 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:38.237 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.148818
2019-10-26 13:59:38.251 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.251 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:38.252 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:38.257 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.133383
2019-10-26 13:59:38.283 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.283 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:38.284 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:38.286 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.980591
2019-10-26 13:59:38.299 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:38.299 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:38.300 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:38.302 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.885735
2019-10-26 13:59:42.141 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:42.141 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:42.141 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:42.141 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:42.141 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:42.143 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.699814ms
2019-10-26 13:59:42.145 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.888508ms
2019-10-26 13:59:42.145 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.248158999999999
2019-10-26 13:59:52.978 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:52.979 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 13:59:52.979 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 13:59:52.979 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 13:59:52.979 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 13:59:52.981 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.961024ms
2019-10-26 13:59:52.981 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.020058ms
2019-10-26 13:59:52.981 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.83118
2019-10-26 13:59:53.848 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.848 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 13:59:53.850 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 13:59:53.853 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.256564
2019-10-26 13:59:53.872 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:53.872 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 13:59:53.874 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 13:59:53.876 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.132936
2019-10-26 13:59:54.093 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.093 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 13:59:54.096 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 13:59:54.098 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.815523000000001
2019-10-26 13:59:54.233 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.233 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 13:59:54.233 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:54.234 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 13:59:54.235 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:54.236 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c"} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", ""} ipVersion=0x4 table="filter"
2019-10-26 13:59:54.236 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-10-26 13:59:54.238 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.689343
2019-10-26 13:59:54.250 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.251 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 13:59:54.251 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 13:59:54.253 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.304132
2019-10-26 13:59:54.279 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.280 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:54.281 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:54.284 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-10-26 13:59:54.287 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.417967
2019-10-26 13:59:54.304 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:54.304 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 13:59:54.305 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 13:59:54.307 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.242791
2019-10-26 13:59:55.241 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.242 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:55.244 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:55.247 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.400868
2019-10-26 13:59:55.292 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:55.292 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:55.294 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:55.296 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.709603
2019-10-26 13:59:56.242 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:56.242 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:56.244 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:56.247 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.360133
2019-10-26 13:59:56.292 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:56.293 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:56.295 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:56.298 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.982572
2019-10-26 13:59:58.243 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:58.243 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 13:59:58.245 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 13:59:58.247 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.983214
2019-10-26 13:59:58.291 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 13:59:58.291 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 13:59:58.293 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 13:59:58.295 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.702673
2019-10-26 14:00:02.242 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:02.242 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:02.243 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:02.246 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.627735
2019-10-26 14:00:02.292 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:02.292 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:02.293 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:02.295 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.31373
2019-10-26 14:00:03.627 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:03.628 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:03.628 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:03.628 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:03.628 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:03.630 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.318924ms
2019-10-26 14:00:03.632 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.639152ms
2019-10-26 14:00:03.632 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.322792
2019-10-26 14:00:10.238 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:10.238 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:10.240 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:10.241 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.860957
2019-10-26 14:00:10.290 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:10.290 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:10.291 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:10.293 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.978032
2019-10-26 14:00:14.220 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:14.220 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:14.220 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:14.220 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:14.221 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:14.223 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.812473ms
2019-10-26 14:00:14.224 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.887116ms
2019-10-26 14:00:14.224 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.174647
2019-10-26 14:00:24.691 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:24.691 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:24.691 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:24.692 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:24.692 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:24.693 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.236948ms
2019-10-26 14:00:24.693 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.384716ms
2019-10-26 14:00:24.693 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.729648
2019-10-26 14:00:25.848 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.848 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:00:25.849 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:00:25.851 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1531599999999997
2019-10-26 14:00:25.870 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:25.870 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:00:25.871 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:00:25.872 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.593368
2019-10-26 14:00:26.091 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.091 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:00:26.093 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:00:26.095 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.361922
2019-10-26 14:00:26.231 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.232 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:00:26.233 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:00:26.234 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.730515
2019-10-26 14:00:26.241 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.241 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:26.242 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:26.243 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.526864
2019-10-26 14:00:26.248 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.248 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:00:26.249 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:00:26.251 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1010500000000003
2019-10-26 14:00:26.290 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.290 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:26.292 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:26.294 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.331612
2019-10-26 14:00:26.299 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:26.299 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:00:26.300 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:00:26.302 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3103070000000003
2019-10-26 14:00:34.898 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:34.899 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:34.899 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:34.899 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:34.899 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:34.900 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.495941ms
2019-10-26 14:00:34.902 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.632783ms
2019-10-26 14:00:34.902 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.196488
2019-10-26 14:00:45.846 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:45.846 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:45.846 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:45.846 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:45.846 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:45.849 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.483464ms
2019-10-26 14:00:45.850 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.068087ms
2019-10-26 14:00:45.850 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.6657949999999997
2019-10-26 14:00:52.816 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:52.816 [INFO][66] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:00:52.816 [INFO][66] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:00:52.817 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.46751699999999996
2019-10-26 14:00:56.450 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:56.450 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:00:56.451 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:00:56.451 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:00:56.451 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:00:56.453 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.673446ms
2019-10-26 14:00:56.455 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.814788ms
2019-10-26 14:00:56.455 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.505144
2019-10-26 14:00:58.238 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.238 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:58.240 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:58.244 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:58.244 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:58.244 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "Cz_u1IQiXIMmKD4c", ""} chainName="INPUT" expectedRuleIDs=[]string{"Cz_u1IQiXIMmKD4c", "", ""} ipVersion=0x4 table="filter"
2019-10-26 14:00:58.245 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.926801
2019-10-26 14:00:58.294 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:58.294 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:58.296 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:58.298 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-10-26 14:00:58.299 [WARNING][66] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-10-26 14:00:58.301 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.698148
2019-10-26 14:00:59.252 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.252 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:00:59.255 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:00:59.258 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.121949
2019-10-26 14:00:59.307 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:00:59.307 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:00:59.309 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:00:59.311 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.287279
2019-10-26 14:01:00.140 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calid649b90758b"
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{}}
2019-10-26 14:01:00.141 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{}}
2019-10-26 14:01:00.141 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{}}
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 471: Linux interface state changed. ifaceName="calid649b90758b" state="up"
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.251266
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calid649b90758b", State:"up"}
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.141 [INFO][66] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calid649b90758b"
2019-10-26 14:01:00.141 [INFO][66] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calid649b90758b"
2019-10-26 14:01:00.141 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:00.141 [INFO][66] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calid649b90758b"
2019-10-26 14:01:00.141 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:00.142 [INFO][66] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.192/32 ifaceName="calid649b90758b" ipVersion=0x4
2019-10-26 14:01:00.142 [INFO][66] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calid649b90758b" ipVersion=0x4
2019-10-26 14:01:00.142 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.858703
2019-10-26 14:01:00.142 [INFO][66] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.142 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.142 [INFO][66] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid649b90758b", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-10-26 14:01:00.142 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.142 [INFO][66] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.128.192/32 ifaceName="calid649b90758b" ipVersion=0x4
2019-10-26 14:01:00.142 [INFO][66] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calid649b90758b" ipVersion=0x4
2019-10-26 14:01:00.143 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.42037599999999997
2019-10-26 14:01:00.146 [INFO][66] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-8g7fl, name=eth0)
2019-10-26 14:01:00.147 [INFO][66] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"allow" rule_id:"YLdFWiauLlZiqqnX" > outbound_rules:<action:"allow" rule_id:"s12JEevpe1A9nAkJ" > > 
2019-10-26 14:01:00.148 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.148 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:00.148 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.149 [INFO][66] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-8g7fl" endpoint_id:"eth0" > endpoint:<state:"active" name:"calid649b90758b" mac:"72:be:e0:e3:69:c4" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-10-26 14:01:00.149 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.149 [INFO][66] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-tw-calid649b90758b" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fw-calid649b90758b" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.149 [INFO][66] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-10-26 14:01:00.149 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:00.149 [INFO][66] 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-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-tw-calid649b90758b" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fw-calid649b90758b" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.149 [INFO][66] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.149 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.150 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-10-26 14:01:00.150 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:00.150 [INFO][66] 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-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.150 [INFO][66] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:00.151 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:00.153 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:00.210 [INFO][66] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:00.210 [INFO][66] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"} status="up"
2019-10-26 14:01:00.210 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=61.094855
2019-10-26 14:01:00.360 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:00.361 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:00.362 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:00.364 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.116079
2019-10-26 14:01:01.161 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.162 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:01.163 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:01.166 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.709814
2019-10-26 14:01:01.214 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:01.215 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:01.216 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:01.220 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.642404999999999
2019-10-26 14:01:01.768 [INFO][66] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-10-26 14:01:02.164 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:02.164 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:02.166 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:02.169 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.878537
2019-10-26 14:01:02.214 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:02.215 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:02.216 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:02.219 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.034513
2019-10-26 14:01:02.305 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:02.305 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:02.306 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:02.308 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.97538
2019-10-26 14:01:04.161 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:04.161 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:04.166 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:04.168 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.752621
2019-10-26 14:01:04.216 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:04.217 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:04.218 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:04.223 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.570639
2019-10-26 14:01:06.307 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:06.307 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:06.309 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:06.310 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.996956
2019-10-26 14:01:06.948 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:06.948 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:06.948 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:06.948 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:06.948 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:06.950 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.342369ms
2019-10-26 14:01:06.950 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.408416ms
2019-10-26 14:01:06.950 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.650633
2019-10-26 14:01:07.868 [INFO][66] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=cmp001, orchestrator=k8s, workload=netchecker/netchecker-agent-8g7fl, name=eth0)
2019-10-26 14:01:07.869 [INFO][66] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-8g7fl" endpoint_id:"eth0" > endpoint:<state:"active" name:"calid649b90758b" mac:"72:be:e0:e3:69:c4" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.128.192/32" > 
2019-10-26 14:01:07.869 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-tw-calid649b90758b" ipVersion=0x4 table="filter"
2019-10-26 14:01:07.869 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-10-26 14:01:07.869 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fw-calid649b90758b" ipVersion=0x4 table="filter"
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:07.869 [INFO][66] 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-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-tw-calid649b90758b" ipVersion=0x6 table="filter"
2019-10-26 14:01:07.869 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-10-26 14:01:07.869 [INFO][66] table.go 417: Queueing update of chain. chainName="cali-fw-calid649b90758b" ipVersion=0x6 table="filter"
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid649b90758b"
2019-10-26 14:01:07.869 [INFO][66] 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-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.869 [INFO][66] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"}
2019-10-26 14:01:07.871 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:07.871 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:07.874 [INFO][66] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-10-26 14:01:07.874 [INFO][66] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-8g7fl", EndpointId:"eth0"} status="up"
2019-10-26 14:01:07.874 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.763344
2019-10-26 14:01:08.163 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.163 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:08.165 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:08.169 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.883812000000001
2019-10-26 14:01:08.216 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:08.216 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:08.217 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:08.221 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.072045
2019-10-26 14:01:14.306 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:14.306 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:14.309 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:14.313 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.757102
2019-10-26 14:01:16.165 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:16.165 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:16.167 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:16.169 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.939064
2019-10-26 14:01:16.214 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:16.214 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:16.217 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:16.219 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.330874000000001
2019-10-26 14:01:17.814 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:17.814 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:17.814 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:17.814 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:17.814 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:17.817 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.323851ms
2019-10-26 14:01:17.817 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.143869ms
2019-10-26 14:01:17.818 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.834979
2019-10-26 14:01:28.750 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:28.750 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:28.750 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:28.750 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:28.750 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:28.753 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.263777ms
2019-10-26 14:01:28.753 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.093903ms
2019-10-26 14:01:28.754 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.572702
2019-10-26 14:01:29.848 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.848 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:01:29.851 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:01:29.854 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.238627
2019-10-26 14:01:29.873 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:29.873 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:01:29.875 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:01:29.877 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.999563
2019-10-26 14:01:30.093 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.093 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:01:30.095 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:01:30.098 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.604857
2019-10-26 14:01:30.233 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.233 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:01:30.235 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:01:30.238 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.189378
2019-10-26 14:01:30.301 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:30.301 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:01:30.301 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:01:30.305 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:01:30.307 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:01:30.309 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.574340999999999
2019-10-26 14:01:32.167 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:32.167 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:01:32.169 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:01:32.172 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.890635
2019-10-26 14:01:32.215 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:32.215 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:01:32.217 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:01:32.219 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.703818
2019-10-26 14:01:39.045 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:39.045 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:39.046 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:39.046 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:39.046 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:39.048 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.306844ms
2019-10-26 14:01:39.048 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.280837ms
2019-10-26 14:01:39.049 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1338690000000002
2019-10-26 14:01:49.429 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:49.430 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:49.430 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:49.430 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:49.430 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:49.433 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.854168ms
2019-10-26 14:01:49.434 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.718982ms
2019-10-26 14:01:49.435 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.179404
2019-10-26 14:01:59.480 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:01:59.480 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:01:59.480 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:01:59.480 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:01:59.480 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:01:59.483 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.993967ms
2019-10-26 14:01:59.483 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.136614ms
2019-10-26 14:01:59.483 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.831281
2019-10-26 14:02:02.301 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:02.303 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:02:02.306 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:02:02.309 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.744353
2019-10-26 14:02:04.165 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:04.165 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:02:04.167 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:02:04.171 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.938614
2019-10-26 14:02:04.216 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:04.216 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:02:04.218 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:02:04.222 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.7868520000000006
2019-10-26 14:02:10.007 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:10.007 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:10.007 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:10.007 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:10.007 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:10.010 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.138393ms
2019-10-26 14:02:10.010 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.235241ms
2019-10-26 14:02:10.010 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7759650000000002
2019-10-26 14:02:20.743 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:20.743 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:20.743 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:20.743 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:20.743 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:20.746 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.851409ms
2019-10-26 14:02:20.746 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.446692ms
2019-10-26 14:02:20.747 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.442649
2019-10-26 14:02:25.561 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:25.561 [INFO][66] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-10-26 14:02:25.561 [INFO][66] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-10-26 14:02:25.563 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.821421
2019-10-26 14:02:31.407 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:31.407 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:31.407 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:31.407 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:31.407 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:31.409 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.36183ms
2019-10-26 14:02:31.409 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.406103ms
2019-10-26 14:02:31.409 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.7533869999999998
2019-10-26 14:02:41.768 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:41.768 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:41.768 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:41.768 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:41.768 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:41.769 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.25761ms
2019-10-26 14:02:41.770 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.235177ms
2019-10-26 14:02:41.770 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.952703
2019-10-26 14:02:52.274 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:52.275 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:02:52.275 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:02:52.276 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:02:52.277 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:02:52.280 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.5585ms
2019-10-26 14:02:52.280 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.516095ms
2019-10-26 14:02:52.281 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.505146
2019-10-26 14:02:59.851 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.851 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-10-26 14:02:59.853 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:02:59.855 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8917230000000003
2019-10-26 14:02:59.879 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:02:59.879 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-10-26 14:02:59.880 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:02:59.881 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.728039
2019-10-26 14:03:00.098 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.098 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-10-26 14:03:00.099 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:03:00.102 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.202573
2019-10-26 14:03:00.240 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.240 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-10-26 14:03:00.241 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:03:00.243 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.2063539999999997
2019-10-26 14:03:00.309 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:00.309 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-10-26 14:03:00.310 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:03:00.312 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.115384
2019-10-26 14:03:02.851 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:02.851 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:02.851 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:02.851 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:02.851 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:02.854 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.224367ms
2019-10-26 14:03:02.854 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.785767ms
2019-10-26 14:03:02.855 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.447209
2019-10-26 14:03:06.301 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:06.301 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-10-26 14:03:06.303 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-10-26 14:03:06.305 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.066077000000001
2019-10-26 14:03:08.162 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:08.162 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-10-26 14:03:08.164 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-10-26 14:03:08.166 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1588089999999998
2019-10-26 14:03:08.213 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:08.213 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-10-26 14:03:08.214 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-10-26 14:03:08.216 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.993324
2019-10-26 14:03:13.228 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:13.228 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:13.228 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:13.228 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:13.228 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:13.230 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.35378ms
2019-10-26 14:03:13.230 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.460891ms
2019-10-26 14:03:13.230 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.7899100000000001
2019-10-26 14:03:23.669 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:23.669 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:23.669 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:23.670 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:23.670 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:23.672 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.344649ms
2019-10-26 14:03:23.672 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.575703ms
2019-10-26 14:03:23.673 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.237714
2019-10-26 14:03:33.899 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:33.900 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:33.900 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:33.900 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:33.901 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:33.902 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.326872ms
2019-10-26 14:03:33.903 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.501696ms
2019-10-26 14:03:33.903 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.901908
2019-10-26 14:03:37.848 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.848 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-10-26 14:03:37.850 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-10-26 14:03:37.853 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.212615
2019-10-26 14:03:37.871 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:37.871 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-10-26 14:03:37.873 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-10-26 14:03:37.875 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.5213229999999998
2019-10-26 14:03:38.093 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.093 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-10-26 14:03:38.094 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-10-26 14:03:38.096 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0197179999999997
2019-10-26 14:03:38.231 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.231 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-10-26 14:03:38.232 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-10-26 14:03:38.234 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7036629999999997
2019-10-26 14:03:38.298 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:38.299 [INFO][66] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-10-26 14:03:38.300 [INFO][66] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-10-26 14:03:38.302 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.755204
2019-10-26 14:03:43.967 [INFO][66] int_dataplane.go 751: Applying dataplane updates
2019-10-26 14:03:43.968 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-10-26 14:03:43.968 [INFO][66] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-10-26 14:03:43.968 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-10-26 14:03:43.968 [INFO][66] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-10-26 14:03:43.971 [INFO][66] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.353594ms
2019-10-26 14:03:43.972 [INFO][66] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.282634ms
2019-10-26 14:03:43.973 [INFO][66] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.331062999999999
