2019-11-16 16:58:20.548 [INFO][68] daemon.go 285: Successfully loaded configuration. GOMAXPROCS=8 buildDate="" config=&config.Config{UseInternalDataplaneDriver:true, DataplaneDriver:"calico-iptables-plugin", DatastoreType:"etcdv3", FelixHostname:"ctl01", EtcdAddr:"127.0.0.1:2379", EtcdScheme:"http", EtcdKeyFile:"/var/lib/etcd/etcd-client.key", EtcdCertFile:"/var/lib/etcd/etcd-client.crt", EtcdCaFile:"/var/lib/etcd/ca.pem", EtcdEndpoints:[]string{"https://172.16.10.36:4001/"}, TyphaAddr:"", TyphaK8sServiceName:"", TyphaK8sNamespace:"kube-system", TyphaReadTimeout:30000000000, TyphaWriteTimeout:10000000000, TyphaKeyFile:"", TyphaCertFile:"", TyphaCAFile:"", TyphaCN:"", TyphaURISAN:"", Ipv6Support:true, IgnoreLooseRPF:false, RouteRefreshInterval:90000000000, IptablesRefreshInterval:90000000000, IptablesPostWriteCheckIntervalSecs:1000000000, IptablesLockFilePath:"/run/xtables.lock", IptablesLockTimeoutSecs:0, IptablesLockProbeIntervalMillis:50000000, IpsetsRefreshInterval:10000000000, MaxIpsetSize:1048576, PolicySyncPathPrefix:"", NetlinkTimeoutSecs:10000000000, MetadataAddr:"", MetadataPort:8775, InterfacePrefix:"cali", InterfaceExclude:"kube-ipvs0", ChainInsertMode:"insert", DefaultEndpointToHostAction:"RETURN", IptablesFilterAllowAction:"ACCEPT", IptablesMangleAllowAction:"ACCEPT", LogPrefix:"calico-packet", LogFilePath:"", LogSeverityFile:"", LogSeverityScreen:"INFO", LogSeveritySys:"", IpInIpEnabled:false, IpInIpMtu:1440, IpInIpTunnelAddr:net.IP(nil), ReportingIntervalSecs:0, ReportingTTLSecs:90000000000, EndpointReportingEnabled:false, EndpointReportingDelaySecs:1000000000, IptablesMarkMask:0xffff0000, DisableConntrackInvalidCheck:false, HealthEnabled:false, HealthPort:9099, HealthHost:"localhost", PrometheusMetricsEnabled:false, PrometheusMetricsPort:9091, PrometheusGoMetricsEnabled:true, PrometheusProcessMetricsEnabled:true, FailsafeInboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"tcp", Port:0x16}, config.ProtoPort{Protocol:"udp", Port:0x44}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, FailsafeOutboundHostPorts:[]config.ProtoPort{config.ProtoPort{Protocol:"udp", Port:0x35}, config.ProtoPort{Protocol:"udp", Port:0x43}, config.ProtoPort{Protocol:"tcp", Port:0xb3}, config.ProtoPort{Protocol:"tcp", Port:0x94b}, config.ProtoPort{Protocol:"tcp", Port:0x94c}, config.ProtoPort{Protocol:"tcp", Port:0x1a0a}, config.ProtoPort{Protocol:"tcp", Port:0x1a0b}}, KubeNodePortRanges:[]numorstring.Port{numorstring.Port{MinPort:0x7530, MaxPort:0x7fff, PortName:""}}, NATPortRange:numorstring.Port{MinPort:0x0, MaxPort:0x0, PortName:""}, UsageReportingEnabled:true, UsageReportingInitialDelaySecs:300000000000, UsageReportingIntervalSecs:86400000000000, ClusterGUID:"6e78891db03e4026a7766acf3b36b7b3", 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{"ClusterType":"k8s,bgp", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3"}, 0x2:map[string]string{"DefaultEndpointToHostAction":"Return"}, 0x4:map[string]string{"etcdendpoints":"https://172.16.10.36:4001", "etcdcafile":"/var/lib/etcd/ca.pem", "felixhostname":"ctl01", "etcdcertfile":"/var/lib/etcd/etcd-client.crt", "etcdkeyfile":"/var/lib/etcd/etcd-client.key"}, 0x3:map[string]string{"MetadataAddr":"None", "LogFilePath":"None", "LogSeverityFile":"None", "LogSeveritySys":"None"}}, rawValues:map[string]string{"EtcdEndpoints":"https://172.16.10.36:4001", "EtcdCaFile":"/var/lib/etcd/ca.pem", "FelixHostname":"ctl01", "LogFilePath":"None", "DefaultEndpointToHostAction":"Return", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "EtcdKeyFile":"/var/lib/etcd/etcd-client.key", "LogSeveritySys":"None", "ReportingIntervalSecs":"0", "EtcdCertFile":"/var/lib/etcd/etcd-client.crt", "ClusterType":"k8s,bgp", "LogSeverityFile":"None", "MetadataAddr":"None", "CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info"}, Err:error(nil)} gitCommit="1edd26adb1cfe5c6ff437467d429608428fbd1fe" version="v3.3.2"
2019-11-16 16:58:20.548 [INFO][68] driver.go 43: Using internal (linux) dataplane driver.
2019-11-16 16:58:20.548 [INFO][68] driver.go 85: Calculated iptables mark bits acceptMark=0x10000 endpointMark=0xfff00000 endpointMarkNonCali=0x100000 passMark=0x20000 scratch0Mark=0x40000 scratch1Mark=0x80000
2019-11-16 16:58:20.549 [INFO][68] 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)(0xc42016c280), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc42016c460), 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)(0xc42027c980), DebugSimulateDataplaneHangAfter:0, ExternalNodesCidrs:[]string(nil)}
2019-11-16 16:58:20.549 [INFO][68] rule_defs.go 283: Creating rule renderer. config=rules.Config{IPSetConfigV4:(*ipsets.IPVersionConfig)(0xc42016c280), IPSetConfigV6:(*ipsets.IPVersionConfig)(0xc42016c460), 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-11-16 16:58:20.549 [INFO][68] rule_defs.go 296: Workload to host packets will be returned to INPUT chain.
2019-11-16 16:58:20.549 [INFO][68] rule_defs.go 307: filter table allowed packets will be accepted immediately.
2019-11-16 16:58:20.549 [INFO][68] rule_defs.go 315: mangle table allowed packets will be accepted immediately.
2019-11-16 16:58:20.550 [INFO][68] 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-11-16 16:58:20.552 [INFO][68] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:20.552 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:20.552 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:20.553 [INFO][68] route_table.go 133: Calculated interface name regexp regex="^cali.*"
2019-11-16 16:58:20.553 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="all-ipam-pools" setType="hash:net"
2019-11-16 16:58:20.553 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="masq-ipam-pools" setType="hash:net"
2019-11-16 16:58:20.553 [INFO][68] int_dataplane.go 424: Registering to report health.
2019-11-16 16:58:20.553 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.553 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.553 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.553 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-FORWARD" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-INPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.554 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-wl-to-host" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-out" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.555 [INFO][68] int_dataplane.go 569: IPIP disabled. Not starting tunnel update thread.
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-POSTROUTING" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-OUTPUT" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.555 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x4 table="mangle"
2019-11-16 16:58:20.556 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x4 table="mangle"
2019-11-16 16:58:20.556 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-failsafe-in" ipVersion=0x6 table="mangle"
2019-11-16 16:58:20.556 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-PREROUTING" ipVersion=0x6 table="mangle"
2019-11-16 16:58:20.556 [INFO][68] daemon.go 299: Connect to the dataplane driver.
2019-11-16 16:58:20.557 [INFO][68] int_dataplane.go 981: Started internal status report thread
2019-11-16 16:58:20.557 [INFO][68] int_dataplane.go 983: Process status reports disabled
2019-11-16 16:58:20.557 [INFO][68] daemon.go 371: Created Syncer syncer=&watchersyncer.watcherSyncer{status:0x0, watcherCaches:[]*watchersyncer.watcherCache{(*watchersyncer.watcherCache)(0xc42014c180), (*watchersyncer.watcherCache)(0xc42014c200), (*watchersyncer.watcherCache)(0xc42014c280), (*watchersyncer.watcherCache)(0xc42014c300), (*watchersyncer.watcherCache)(0xc42014c380), (*watchersyncer.watcherCache)(0xc42014c400), (*watchersyncer.watcherCache)(0xc42014c700), (*watchersyncer.watcherCache)(0xc42014c780), (*watchersyncer.watcherCache)(0xc42014c800), (*watchersyncer.watcherCache)(0xc42014c880)}, results:(chan interface {})(0xc420168780), numSynced:0, callbacks:(*calc.SyncerCallbacksDecoupler)(0xc42016e0f8), wgwc:(*sync.WaitGroup)(nil), wgws:(*sync.WaitGroup)(nil), cancel:(context.CancelFunc)(nil)}
2019-11-16 16:58:20.557 [INFO][68] int_dataplane.go 594: Started internal iptables dataplane driver loop
2019-11-16 16:58:20.558 [INFO][68] iface_monitor.go 88: Interface monitoring thread started.
2019-11-16 16:58:20.558 [INFO][68] int_dataplane.go 604: Will refresh IP sets on timer interval=1m30s
2019-11-16 16:58:20.557 [INFO][68] calc_graph.go 96: Creating calculation graph, filtered to hostname ctl01
2019-11-16 16:58:20.558 [INFO][68] iface_monitor.go 95: Subscribed to netlink updates.
2019-11-16 16:58:20.558 [INFO][68] int_dataplane.go 614: Will refresh routes on timer interval=1m30s
2019-11-16 16:58:20.558 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:20.558 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2a30)
2019-11-16 16:58:20.558 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:20.558 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2af0)
2019-11-16 16:58:20.558 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="lo" state="up"
2019-11-16 16:58:20.558 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileRulesKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x12a2920)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileTagsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:20.559 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"127.0.0.1":set.empty{}, "::1":set.empty{}} ifaceName="lo"
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.NetworkSetKey: (dispatcher.UpdateHandler)(0x120eed0)
2019-11-16 16:58:20.559 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="ens3" state="up"
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.PolicyKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2ce0)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.IPPoolKey: (dispatcher.UpdateHandler)(0x12a2c20)
2019-11-16 16:58:20.559 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"192.168.11.21":set.empty{}, "fe80::5054:ff:fe9c:aaa4":set.empty{}} ifaceName="ens3"
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.GlobalConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ReadyFlagKey: (dispatcher.UpdateHandler)(0x12a2b60)
2019-11-16 16:58:20.559 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="ens4" state="up"
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.ProfileLabelsKey: (dispatcher.UpdateHandler)(0x12a2e10)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostIPKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.WorkloadEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostEndpointKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:20.559 [INFO][68] dispatcher.go 68: Registering listener for type model.HostConfigKey: (dispatcher.UpdateHandler)(0x12a2e80)
2019-11-16 16:58:20.559 [INFO][68] daemon.go 439: Starting the datastore Syncer
2019-11-16 16:58:20.559 [INFO][68] watchersyncer.go 89: Start called
2019-11-16 16:58:20.559 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe9d:e75c":set.empty{}} ifaceName="ens4"
2019-11-16 16:58:20.559 [INFO][68] async_calc_graph.go 229: Starting AsyncCalcGraph
2019-11-16 16:58:20.559 [INFO][68] daemon.go 454: Started the processing graph
2019-11-16 16:58:20.560 [INFO][68] daemon.go 813: Reading from dataplane driver pipe...
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5" state="up"
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}} ifaceName="ens5"
2019-11-16 16:58:20.560 [INFO][68] watchersyncer.go 127: Sending status update Status=wait-for-ready
2019-11-16 16:58:20.560 [INFO][68] watchersyncer.go 147: Starting main event processing loop
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="ens6"
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="br-mgmt" state="up"
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe9d:e75c":set.empty{}} ifaceName="br-mgmt"
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="ens5.1000" state="up"
2019-11-16 16:58:20.560 [INFO][68] async_calc_graph.go 134: AsyncCalcGraph running
2019-11-16 16:58:20.560 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}} ifaceName="ens5.1000"
2019-11-16 16:58:20.561 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"lo", State:"up"}
2019-11-16 16:58:20.561 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens3", State:"up"}
2019-11-16 16:58:20.561 [INFO][68] daemon.go 546: No driver process to monitor
2019-11-16 16:58:20.561 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/hostendpoints"
2019-11-16 16:58:20.561 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens4", State:"up"}
2019-11-16 16:58:20.562 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.562 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5", State:"up"}
2019-11-16 16:58:20.562 [INFO][68] watchersyncer.go 127: Sending status update Status=resync
2019-11-16 16:58:20.562 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"br-mgmt", State:"up"}
2019-11-16 16:58:20.562 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"ens5.1000", State:"up"}
2019-11-16 16:58:20.562 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/profiles"
2019-11-16 16:58:20.562 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/networkpolicies"
2019-11-16 16:58:20.562 [INFO][68] 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-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.563 [INFO][68] 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-11-16 16:58:20.563 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/ippools"
2019-11-16 16:58:20.563 [INFO][68] 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-11-16 16:58:20.563 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/clusterinformations"
2019-11-16 16:58:20.563 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"fe80::5054:ff:fe9c:aaa4":set.empty{}, "192.168.11.21":set.empty{}}}
2019-11-16 16:58:20.563 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.21":set.empty{}, "fe80::5054:ff:fe9c:aaa4":set.empty{}}}
2019-11-16 16:58:20.563 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/nodes"
2019-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/workloadendpoints"
2019-11-16 16:58:20.563 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens3", Addrs:set.mapSet{"192.168.11.21":set.empty{}, "fe80::5054:ff:fe9c:aaa4":set.empty{}}}
2019-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.563 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.563 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe9d:e75c":set.empty{}}}
2019-11-16 16:58:20.563 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe9d:e75c":set.empty{}}}
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworkpolicies"
2019-11-16 16:58:20.563 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/globalnetworksets"
2019-11-16 16:58:20.563 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens4", Addrs:set.mapSet{"fe80::5054:ff:fe9d:e75c":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens6", Addrs:set.mapSet{}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe9d:e75c":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"172.16.10.36":set.empty{}, "fe80::5054:ff:fe9d:e75c":set.empty{}}}
2019-11-16 16:58:20.564 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.564 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"br-mgmt", Addrs:set.mapSet{"fe80::5054:ff:fe9d:e75c":set.empty{}, "172.16.10.36":set.empty{}}}
2019-11-16 16:58:20.565 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.565 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.565 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.565 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.565 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"ens5.1000", Addrs:set.mapSet{"fe80::5054:ff:fe08:c5ff":set.empty{}}}
2019-11-16 16:58:20.565 [INFO][68] ipsets.go 119: Queueing IP set for creation family="inet6" setID="this-host" setType="hash:ip"
2019-11-16 16:58:20.565 [INFO][68] int_dataplane.go 630: Received *proto.ConfigUpdate update from calculation graph msg=config:<key:"CalicoVersion" value:"v3.3.2" > config:<key:"ClusterGUID" value:"6e78891db03e4026a7766acf3b36b7b3" > config:<key:"ClusterType" value:"k8s,bgp" > config:<key:"DefaultEndpointToHostAction" value:"Return" > config:<key:"EtcdCaFile" value:"/var/lib/etcd/ca.pem" > config:<key:"EtcdCertFile" value:"/var/lib/etcd/etcd-client.crt" > config:<key:"EtcdEndpoints" value:"https://172.16.10.36:4001" > config:<key:"EtcdKeyFile" value:"/var/lib/etcd/etcd-client.key" > config:<key:"FelixHostname" value:"ctl01" > config:<key:"LogFilePath" value:"None" > config:<key:"LogSeverityFile" value:"None" > config:<key:"LogSeverityScreen" value:"Info" > config:<key:"LogSeveritySys" value:"None" > config:<key:"MetadataAddr" value:"None" > config:<key:"ReportingIntervalSecs" value:"0" > 
2019-11-16 16:58:20.563 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.567 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.567 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.567 [INFO][68] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterGUID) 6e78891db03e4026a7766acf3b36b7b3 6 0s} 1}
2019-11-16 16:58:20.567 [INFO][68] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ClusterType) k8s,bgp 6 0s} 1}
2019-11-16 16:58:20.567 [INFO][68] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=CalicoVersion) v3.3.2 6 0s} 1}
2019-11-16 16:58:20.567 [INFO][68] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=LogSeverityScreen) Info 7 0s} 1}
2019-11-16 16:58:20.567 [INFO][68] config_batcher.go 74: Global config update: {{GlobalFelixConfig(name=ReportingIntervalSecs) 0 7 0s} 1}
2019-11-16 16:58:20.568 [INFO][68] config_batcher.go 61: Host config update for this host: {{HostConfig(node=ctl01,name=DefaultEndpointToHostAction) Return 12 0s} 1}
2019-11-16 16:58:20.568 [INFO][68] watchercache.go 271: Sending synced update ListRoot="/calico/resources/v3/projectcalico.org/felixconfigurations"
2019-11-16 16:58:20.568 [INFO][68] watchersyncer.go 209: Received InSync event from one of the watcher caches
2019-11-16 16:58:20.568 [INFO][68] watchersyncer.go 221: All watchers have sync'd data - sending data and final sync
2019-11-16 16:58:20.568 [INFO][68] watchersyncer.go 127: Sending status update Status=in-sync
2019-11-16 16:58:20.568 [INFO][68] config_batcher.go 102: Datamodel in sync, flushing config update
2019-11-16 16:58:20.569 [INFO][68] config_batcher.go 112: Sending config update global: map[ReportingIntervalSecs:0 ClusterGUID:6e78891db03e4026a7766acf3b36b7b3 ClusterType:k8s,bgp CalicoVersion:v3.3.2 LogSeverityScreen:Info], host: map[DefaultEndpointToHostAction:Return].
2019-11-16 16:58:20.569 [INFO][68] async_calc_graph.go 160: First time we've been in sync
2019-11-16 16:58:20.569 [INFO][68] event_sequencer.go 210: Possible config update. global=map[string]string{"CalicoVersion":"v3.3.2", "LogSeverityScreen":"Info", "ReportingIntervalSecs":"0", "ClusterGUID":"6e78891db03e4026a7766acf3b36b7b3", "ClusterType":"k8s,bgp"} host=map[string]string{"DefaultEndpointToHostAction":"Return"}
2019-11-16 16:58:20.569 [INFO][68] config_params.go 217: Merging in config from datastore (global): map[LogSeverityScreen:Info ReportingIntervalSecs:0 ClusterGUID:6e78891db03e4026a7766acf3b36b7b3 ClusterType:k8s,bgp CalicoVersion:v3.3.2]
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:20.569 [INFO][68] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] usagerep.go 83: Waiting before first check-in delay=5m2.304s
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:20.569 [INFO][68] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:20.569 [INFO][68] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:20.569 [INFO][68] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:20.570 [INFO][68] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 217: Merging in config from datastore (per-host): map[DefaultEndpointToHostAction:Return]
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for FelixHostname: ctl01 (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for FelixHostname: ctl01 (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.crt"
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for EtcdCertFile: /var/lib/etcd/etcd-client.crt (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/etcd-client.key"
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for EtcdKeyFile: /var/lib/etcd/etcd-client.key (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for EtcdEndpoints: https://172.16.10.36:4001 (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for EtcdEndpoints: [https://172.16.10.36:4001/] (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] param_types.go 220: Looking for required file path="/var/lib/etcd/ca.pem"
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for EtcdCaFile: /var/lib/etcd/ca.pem (from environment variable)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for LogFilePath: None (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for LogFilePath:  (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for LogSeverityFile: None (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for LogSeverityFile:  (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for LogSeveritySys: None (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for LogSeveritySys:  (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for MetadataAddr: None (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 319: Value set to 'none', replacing with zero-value: "".
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for MetadataAddr:  (from config file)
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for DefaultEndpointToHostAction: Return (from datastore (per-host))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for DefaultEndpointToHostAction: RETURN (from datastore (per-host))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for ClusterGUID: 6e78891db03e4026a7766acf3b36b7b3 (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for ClusterType: k8s,bgp (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for CalicoVersion: v3.3.2 (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for LogSeverityScreen: Info (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 338: Parsed value for LogSeverityScreen: INFO (from datastore (global))
2019-11-16 16:58:20.571 [INFO][68] config_params.go 302: Parsing value for ReportingIntervalSecs: 0 (from datastore (global))
2019-11-16 16:58:20.572 [INFO][68] config_params.go 338: Parsed value for ReportingIntervalSecs: 0s (from datastore (global))
2019-11-16 16:58:20.572 [INFO][68] async_calc_graph.go 209: First flush after becoming in sync, sending InSync message.
2019-11-16 16:58:20.572 [INFO][68] daemon.go 892: Datastore now in sync.
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp001" ipv4_addr:"172.16.10.55" 
2019-11-16 16:58:20.572 [INFO][68] daemon.go 894: Datastore in sync for first time, sending message to status reporter.
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"cmp002" ipv4_addr:"172.16.10.56" 
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 630: Received *proto.HostMetadataUpdate update from calculation graph msg=hostname:"ctl01" ipv4_addr:"172.16.10.36" 
2019-11-16 16:58:20.572 [INFO][68] 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-11-16 16:58:20.572 [INFO][68] int_dataplane.go 630: Received *proto.IPAMPoolUpdate update from calculation graph msg=id:"fd0b:52a8:5995::-48" pool:<cidr:"fd0b:52a8:5995::/48" > 
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 630: Received *proto.InSync update from calculation graph msg=
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 638: Datastore in sync, flushing the dataplane for the first time... timeSinceStart=141.349421ms
2019-11-16 16:58:20.572 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:20.572 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.572 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.572 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x4 table="filter"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="mangle"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x4 table="raw"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.573 [INFO][68] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x4
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x4 table="nat"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.573 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-hep-forward" ipVersion=0x6 table="filter"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="mangle"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-host-endpoint" ipVersion=0x6 table="raw"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fip-dnat" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fip-snat" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.574 [INFO][68] masq_mgr.go 144: IPAM pools updated, refreshing iptables rule ipVersion=0x6
2019-11-16 16:58:20.574 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-nat-outgoing" ipVersion=0x6 table="nat"
2019-11-16 16:58:20.574 [INFO][68] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:20.574 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:20.574 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:20.574 [INFO][68] route_table.go 199: Trying to connect to netlink
2019-11-16 16:58:20.585 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=10.393533ms
2019-11-16 16:58:20.585 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=10.337502ms
2019-11-16 16:58:20.585 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:20.585 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=0 setID="masq-ipam-pools"
2019-11-16 16:58:20.586 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="all-ipam-pools"
2019-11-16 16:58:20.586 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=1 setID="masq-ipam-pools"
2019-11-16 16:58:20.586 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet" numMembersInPendingReplace=3 setID="this-host"
2019-11-16 16:58:20.585 [INFO][68] ipsets.go 697: Doing full IP set rewrite family="inet6" numMembersInPendingReplace=4 setID="this-host"
2019-11-16 16:58:20.715 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:20.718 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:20.718 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:20.720 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:20.721 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:20.725 [WARNING][68] table.go 650: iptables save failed error=exit status 1
2019-11-16 16:58:20.725 [WARNING][68] table.go 599: ip6tables-save command failed error=exit status 1 ipVersion=0x6 stderr="" table="nat"
2019-11-16 16:58:20.725 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:20.728 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:20.730 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:20.730 [WARNING][68] table.go 650: iptables save failed error=exit status 1
2019-11-16 16:58:20.730 [WARNING][68] table.go 599: ip6tables-save command failed error=exit status 1 ipVersion=0x6 stderr="" table="filter"
2019-11-16 16:58:21.317 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=744.251875
2019-11-16 16:58:21.317 [INFO][68] int_dataplane.go 771: Completed first update to dataplane. secsSinceStart=0.885778759
2019-11-16 16:58:22.431 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.431 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:22.431 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:22.431 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:22.431 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:22.432 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:22.432 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:22.432 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:22.432 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:22.433 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:22.434 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:22.437 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:22.439 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:22.440 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:22.442 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:22.443 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:22.444 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:22.447 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=15.966327999999999
2019-11-16 16:58:22.844 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.844 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:22.844 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:22.846 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:22.847 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:22.848 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.823404
2019-11-16 16:58:22.869 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:22.869 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:22.869 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:22.871 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.143961
2019-11-16 16:58:23.092 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:23.093 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:23.095 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:23.096 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.610076
2019-11-16 16:58:23.101 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:23.101 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:23.102 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:23.104 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.157944
2019-11-16 16:58:23.284 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:23.285 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:23.286 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:23.287 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3957520000000003
2019-11-16 16:58:23.297 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:23.297 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:23.298 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:23.300 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.447605
2019-11-16 16:58:23.319 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:23.319 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:23.320 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:23.321 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.160434
2019-11-16 16:58:24.831 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.831 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:24.832 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:24.834 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1297870000000003
2019-11-16 16:58:24.844 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.844 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:24.845 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:24.846 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.598075
2019-11-16 16:58:24.867 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:24.868 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:24.869 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:24.871 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.38142
2019-11-16 16:58:25.093 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:25.094 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:25.095 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:25.096 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6509
2019-11-16 16:58:25.100 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:25.101 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:25.104 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:25.105 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.733752
2019-11-16 16:58:25.287 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:25.287 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:25.288 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:25.290 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.715102
2019-11-16 16:58:25.297 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:25.298 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:25.299 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:25.300 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.695677
2019-11-16 16:58:25.319 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:25.319 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:25.320 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:25.321 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.8541219999999998
2019-11-16 16:58:28.830 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.830 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:28.831 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:28.833 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.588004
2019-11-16 16:58:28.843 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.844 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:28.845 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:28.847 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.051469
2019-11-16 16:58:28.868 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:28.868 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:28.869 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:28.870 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.663061
2019-11-16 16:58:29.093 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:29.093 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:29.094 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:29.096 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.8501220000000003
2019-11-16 16:58:29.101 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:29.101 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:29.102 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:29.103 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.417923
2019-11-16 16:58:29.285 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:29.285 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:29.286 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:29.288 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1355
2019-11-16 16:58:29.298 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:29.298 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:29.299 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:29.302 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.265060999999999
2019-11-16 16:58:29.321 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:29.321 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:29.322 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:29.323 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.51362
2019-11-16 16:58:30.921 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:30.921 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:30.921 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:30.921 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:30.921 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:30.922 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.249018ms
2019-11-16 16:58:30.922 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.360128ms
2019-11-16 16:58:30.923 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.74136
2019-11-16 16:58:36.829 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.829 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:36.832 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:36.834 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.281747
2019-11-16 16:58:36.846 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.846 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:36.847 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:36.848 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.28532
2019-11-16 16:58:36.867 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:36.867 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:36.868 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:36.870 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.465876
2019-11-16 16:58:37.093 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:37.093 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:37.094 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:37.095 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.458679
2019-11-16 16:58:37.100 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:37.100 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:37.101 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:37.103 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.4777470000000004
2019-11-16 16:58:37.285 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:37.285 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:37.286 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:37.287 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.501783
2019-11-16 16:58:37.297 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:37.297 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:37.299 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:37.300 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.485796
2019-11-16 16:58:37.320 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:37.320 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:37.321 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:37.322 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.258903
2019-11-16 16:58:41.366 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:41.366 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:41.366 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:41.366 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:41.366 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:41.369 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.676897ms
2019-11-16 16:58:41.370 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.451503ms
2019-11-16 16:58:41.370 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.083221
2019-11-16 16:58:51.579 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:51.579 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:58:51.579 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:58:51.579 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:58:51.579 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:58:51.581 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.206073ms
2019-11-16 16:58:51.581 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.785342ms
2019-11-16 16:58:51.581 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.06351
2019-11-16 16:58:52.829 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.829 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:58:52.830 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:58:52.832 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.448857
2019-11-16 16:58:52.844 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.844 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:58:52.845 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:58:52.847 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1939490000000004
2019-11-16 16:58:52.868 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:52.868 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:58:52.869 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:58:52.871 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.5230729999999997
2019-11-16 16:58:53.093 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:53.093 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:58:53.096 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:58:53.097 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.360290999999999
2019-11-16 16:58:53.102 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:53.102 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:58:53.103 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:58:53.104 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.176034
2019-11-16 16:58:53.284 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:53.284 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:58:53.286 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:58:53.287 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.488518
2019-11-16 16:58:53.297 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:53.297 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:58:53.298 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:58:53.300 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7154190000000002
2019-11-16 16:58:53.319 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:58:53.319 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:58:53.320 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:58:53.321 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.031182
2019-11-16 16:59:02.374 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:02.375 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:02.375 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:02.375 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:02.375 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:02.376 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.105968ms
2019-11-16 16:59:02.376 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.471454ms
2019-11-16 16:59:02.376 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.905655
2019-11-16 16:59:12.774 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:12.775 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:12.775 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:12.775 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:12.775 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:12.777 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.196247ms
2019-11-16 16:59:12.777 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.443046ms
2019-11-16 16:59:12.778 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.961713
2019-11-16 16:59:23.736 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:23.737 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:23.737 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:23.737 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:23.738 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:23.739 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.457552ms
2019-11-16 16:59:23.740 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.665739ms
2019-11-16 16:59:23.740 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1093919999999997
2019-11-16 16:59:24.829 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.829 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:24.830 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:24.831 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="filter"
2019-11-16 16:59:24.832 [WARNING][68] 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-11-16 16:59:24.833 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.3688959999999994
2019-11-16 16:59:24.845 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.845 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 16:59:24.846 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 16:59:24.848 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0855409999999996
2019-11-16 16:59:24.868 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:24.868 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 16:59:24.870 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 16:59:24.871 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.079185
2019-11-16 16:59:25.093 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.093 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:25.095 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:25.098 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "O3lYWMrLQYEMJtB5"} chainName="POSTROUTING" expectedRuleIDs=[]string{"O3lYWMrLQYEMJtB5", ""} ipVersion=0x4 table="nat"
2019-11-16 16:59:25.099 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.0284889999999995
2019-11-16 16:59:25.104 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.104 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 16:59:25.105 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 16:59:25.106 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3809880000000003
2019-11-16 16:59:25.285 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.285 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 16:59:25.286 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 16:59:25.288 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.19136
2019-11-16 16:59:25.297 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.298 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 16:59:25.299 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 16:59:25.301 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.7347259999999998
2019-11-16 16:59:25.320 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.320 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 16:59:25.321 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 16:59:25.323 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.3730610000000003
2019-11-16 16:59:25.835 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:25.836 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:25.837 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:25.839 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.668988
2019-11-16 16:59:26.103 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:26.103 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:26.105 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:26.106 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.167917
2019-11-16 16:59:26.836 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:26.837 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:26.838 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:26.841 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.628425
2019-11-16 16:59:27.104 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:27.104 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:27.106 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:27.108 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.1750169999999995
2019-11-16 16:59:28.837 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:28.837 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:28.840 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:28.842 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.400928
2019-11-16 16:59:29.105 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:29.105 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:29.107 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:29.109 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.491968
2019-11-16 16:59:32.838 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:32.838 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:32.839 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:32.842 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.034727
2019-11-16 16:59:33.103 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:33.103 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:33.105 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:33.107 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.680406
2019-11-16 16:59:34.663 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:34.663 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:34.664 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:34.664 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:34.664 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:34.666 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.705159ms
2019-11-16 16:59:34.667 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.868047ms
2019-11-16 16:59:34.667 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.533534
2019-11-16 16:59:40.833 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:40.833 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:40.835 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:40.837 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.369263
2019-11-16 16:59:41.103 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:41.103 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:41.105 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:41.108 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.15754
2019-11-16 16:59:45.518 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:45.518 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:45.521 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:45.521 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:45.521 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:45.522 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.346707ms
2019-11-16 16:59:45.523 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.95821ms
2019-11-16 16:59:45.523 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.97698
2019-11-16 16:59:54.416 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:54.417 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 16:59:54.417 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 16:59:54.417 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.370061
2019-11-16 16:59:55.863 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:55.863 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 16:59:55.863 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 16:59:55.863 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 16:59:55.863 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 16:59:55.864 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.294216ms
2019-11-16 16:59:55.865 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.740957ms
2019-11-16 16:59:55.865 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.593425
2019-11-16 16:59:56.833 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:56.834 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 16:59:56.835 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 16:59:56.839 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.568725
2019-11-16 16:59:57.105 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 16:59:57.105 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 16:59:57.107 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 16:59:57.110 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.094195
2019-11-16 17:00:06.390 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:06.390 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:06.390 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:06.390 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:06.390 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:06.391 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.124807ms
2019-11-16 17:00:06.394 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.512362ms
2019-11-16 17:00:06.394 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.9640329999999997
2019-11-16 17:00:16.815 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:16.815 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:16.815 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:16.815 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:16.815 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:16.816 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.184067ms
2019-11-16 17:00:16.816 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.109826ms
2019-11-16 17:00:16.817 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.487943
2019-11-16 17:00:26.969 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:26.969 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:26.969 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:26.969 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:26.969 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:26.971 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.818972ms
2019-11-16 17:00:26.971 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.114478ms
2019-11-16 17:00:26.972 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.82293
2019-11-16 17:00:28.833 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.833 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:28.835 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:28.836 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0", ""} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", "", ""} ipVersion=0x4 table="filter"
2019-11-16 17:00:28.836 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "wUHhoiAYhphO9Mso"} chainName="FORWARD" expectedRuleIDs=[]string{"wUHhoiAYhphO9Mso", ""} ipVersion=0x4 table="filter"
2019-11-16 17:00:28.836 [WARNING][68] 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-11-16 17:00:28.838 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.527083
2019-11-16 17:00:28.845 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.845 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:00:28.846 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:00:28.848 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.751602
2019-11-16 17:00:28.867 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:28.868 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:00:28.868 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:00:28.870 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.831638
2019-11-16 17:00:29.101 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.101 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:00:29.101 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:29.103 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:00:29.105 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:29.108 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "6gwbT8clXdHdC1b1"} chainName="PREROUTING" expectedRuleIDs=[]string{"6gwbT8clXdHdC1b1", ""} ipVersion=0x4 table="nat"
2019-11-16 17:00:29.108 [WARNING][68] table.go 508: Detected out-of-sync inserts, marking for resync actualRuleIDs=[]string{"", "tVnHkvAo15HuiPy0"} chainName="OUTPUT" expectedRuleIDs=[]string{"tVnHkvAo15HuiPy0", ""} ipVersion=0x4 table="nat"
2019-11-16 17:00:29.109 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.603265
2019-11-16 17:00:29.291 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.292 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:00:29.294 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:00:29.297 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.721577
2019-11-16 17:00:29.299 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.299 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:29.300 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:29.302 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.31367
2019-11-16 17:00:29.320 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.320 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:00:29.322 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:00:29.323 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4356389999999997
2019-11-16 17:00:29.841 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:29.841 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:29.843 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:29.846 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.961849
2019-11-16 17:00:30.115 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.115 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:30.117 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:30.120 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.253793
2019-11-16 17:00:30.843 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:30.843 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:30.845 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:30.847 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.940054
2019-11-16 17:00:31.113 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:31.114 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:31.115 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:31.118 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.499286
2019-11-16 17:00:32.842 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:32.842 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:32.843 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:32.845 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.232917
2019-11-16 17:00:33.113 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:33.113 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:33.114 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:33.116 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.746461
2019-11-16 17:00:36.842 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:36.842 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:36.843 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:36.845 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.519593
2019-11-16 17:00:37.113 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:37.113 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:37.117 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:37.120 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.546355999999999
2019-11-16 17:00:37.227 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:37.227 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:37.227 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:37.227 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:37.227 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:37.228 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.046404ms
2019-11-16 17:00:37.228 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.289289ms
2019-11-16 17:00:37.228 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.5500880000000001
2019-11-16 17:00:41.151 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{} ifaceName="calid435d8ab847"
2019-11-16 17:00:41.151 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{}}
2019-11-16 17:00:41.151 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{}}
2019-11-16 17:00:41.151 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{}}
2019-11-16 17:00:41.151 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:41.151 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.226881
2019-11-16 17:00:41.152 [INFO][68] int_dataplane.go 471: Linux interface state changed. ifaceName="calid435d8ab847" state="up"
2019-11-16 17:00:41.153 [INFO][68] int_dataplane.go 645: Received interface update msg=&intdataplane.ifaceUpdate{Name:"calid435d8ab847", State:"up"}
2019-11-16 17:00:41.153 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:41.153 [INFO][68] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.153 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.154 [INFO][68] endpoint_mgr.go 253: Workload interface came up, marking for reconfiguration. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.154 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.155 [INFO][68] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="calid435d8ab847" ipVersion=0x4
2019-11-16 17:00:41.155 [INFO][68] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calid435d8ab847" ipVersion=0x4
2019-11-16 17:00:41.155 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.1243920000000003
2019-11-16 17:00:41.156 [INFO][68] int_dataplane.go 504: Linux interface addrs changed. addrs=set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}} ifaceName="calid435d8ab847"
2019-11-16 17:00:41.156 [INFO][68] int_dataplane.go 660: Received interface addresses update msg=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:41.156 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:41.156 [INFO][68] hostip_mgr.go 84: Interface addrs changed. update=&intdataplane.ifaceAddrsUpdate{Name:"calid435d8ab847", Addrs:set.mapSet{"fe80::ecee:eeff:feee:eeee":set.empty{}}}
2019-11-16 17:00:41.156 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:41.157 [INFO][68] route_table.go 442: Syncing routes: found unexpected route; ignoring due to grace period. dest=192.168.237.0/32 ifaceName="calid435d8ab847" ipVersion=0x4
2019-11-16 17:00:41.157 [INFO][68] route_table.go 298: Interface in cleanup grace period, will retry after. ifaceName="calid435d8ab847" ipVersion=0x4
2019-11-16 17:00:41.157 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=0.86248
2019-11-16 17:00:41.159 [INFO][68] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-2vjgr, name=eth0)
2019-11-16 17:00:41.159 [WARNING][68] active_rules_calculator.go 326: Profile not known or invalid, generating dummy profile that drops all traffic. profileID="calico-k8s-network"
2019-11-16 17:00:41.159 [INFO][68] int_dataplane.go 630: Received *proto.ActiveProfileUpdate update from calculation graph msg=id:<name:"calico-k8s-network" > profile:<inbound_rules:<action:"deny" rule_id:"oj2OqMy9CAebzGBO" > outbound_rules:<action:"deny" rule_id:"Eaor-oJ4HE6fBT4g" > > 
2019-11-16 17:00:41.160 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.160 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:41.160 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.160 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.160 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:41.160 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.160 [INFO][68] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-2vjgr" endpoint_id:"eth0" > endpoint:<state:"active" name:"calid435d8ab847" mac:"ea:94:64:92:ff:60" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-11-16 17:00:41.160 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:41.160 [INFO][68] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-tw-calid435d8ab847" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fw-calid435d8ab847" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.161 [INFO][68] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.161 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.161 [INFO][68] 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-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-tw-calid435d8ab847" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fw-calid435d8ab847" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.161 [INFO][68] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-from-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.161 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-to-wl-dispatch" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.161 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:41.161 [INFO][68] 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-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.161 [INFO][68] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:41.163 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:41.168 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:41.172 [INFO][68] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"} ipVersion=0x6 status="up"
2019-11-16 17:00:41.172 [INFO][68] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"} status="up"
2019-11-16 17:00:41.172 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=11.674369
2019-11-16 17:00:41.172 [INFO][68] 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-11-16 17:00:41.172 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.172 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:41.173 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x4 table="filter"
2019-11-16 17:00:41.173 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pri-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.173 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:41.173 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-pro-calico-k8s-network" ipVersion=0x6 table="filter"
2019-11-16 17:00:41.173 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:41.174 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:41.178 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:41.181 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=8.765462
2019-11-16 17:00:42.189 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:42.190 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:42.190 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:42.191 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:42.193 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:42.196 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.384518
2019-11-16 17:00:42.206 [INFO][68] iface_monitor.go 176: Netlink address update. addr="fe80::ecee:eeff:feee:eeee" exists=true ifIndex=8
2019-11-16 17:00:43.187 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:43.187 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:43.187 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:43.188 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:43.189 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:43.191 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.367877
2019-11-16 17:00:45.114 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:45.114 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:00:45.115 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:00:45.117 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.248384
2019-11-16 17:00:45.184 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:45.184 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:45.184 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:45.185 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:45.189 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:45.192 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.6326279999999995
2019-11-16 17:00:47.372 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:47.372 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:47.372 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:47.372 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:47.373 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:47.374 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.460877ms
2019-11-16 17:00:47.375 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.118968ms
2019-11-16 17:00:47.375 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.502778
2019-11-16 17:00:48.745 [INFO][68] calc_graph.go 361: Local endpoint updated id=WorkloadEndpoint(node=ctl01, orchestrator=k8s, workload=netchecker/netchecker-agent-2vjgr, name=eth0)
2019-11-16 17:00:48.745 [INFO][68] int_dataplane.go 630: Received *proto.WorkloadEndpointUpdate update from calculation graph msg=id:<orchestrator_id:"k8s" workload_id:"netchecker/netchecker-agent-2vjgr" endpoint_id:"eth0" > endpoint:<state:"active" name:"calid435d8ab847" mac:"ea:94:64:92:ff:60" profile_ids:"calico-k8s-network" ipv4_nets:"192.168.237.0/32" > 
2019-11-16 17:00:48.745 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:48.746 [INFO][68] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.746 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-tw-calid435d8ab847" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.746 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="chain update" table="filter"
2019-11-16 17:00:48.746 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fw-calid435d8ab847" ipVersion=0x4 table="filter"
2019-11-16 17:00:48.746 [INFO][68] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.747 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:48.747 [INFO][68] 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-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.747 [INFO][68] status_combiner.go 58: Storing endpoint status update ipVersion=0x4 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.747 [INFO][68] endpoint_mgr.go 408: Updating per-endpoint chains. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.747 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-tw-calid435d8ab847" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.747 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="chain update" table="filter"
2019-11-16 17:00:48.748 [INFO][68] table.go 417: Queueing update of chain. chainName="cali-fw-calid435d8ab847" ipVersion=0x6 table="filter"
2019-11-16 17:00:48.748 [INFO][68] endpoint_mgr.go 435: Updating endpoint routes. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.748 [INFO][68] endpoint_mgr.go 811: Applying /proc/sys configuration to interface. ifaceName="calid435d8ab847"
2019-11-16 17:00:48.748 [INFO][68] 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-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.748 [INFO][68] status_combiner.go 58: Storing endpoint status update ipVersion=0x6 status="up" workload=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"}
2019-11-16 17:00:48.756 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:48.757 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:48.760 [INFO][68] status_combiner.go 81: Endpoint up for at least one IP version id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"} ipVersion=0x4 status="up"
2019-11-16 17:00:48.760 [INFO][68] status_combiner.go 98: Reporting combined status. id=proto.WorkloadEndpointID{OrchestratorId:"k8s", WorkloadId:"netchecker/netchecker-agent-2vjgr", EndpointId:"eth0"} status="up"
2019-11-16 17:00:48.760 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=14.750354999999999
2019-11-16 17:00:49.188 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:49.188 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:49.188 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:49.191 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:49.194 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:49.198 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.706266
2019-11-16 17:00:57.190 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:57.191 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:00:57.191 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:00:57.192 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:00:57.194 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:00:57.196 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.015283
2019-11-16 17:00:58.036 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:00:58.036 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:00:58.036 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:00:58.036 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:00:58.036 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:00:58.038 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.013247ms
2019-11-16 17:00:58.040 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=3.431063ms
2019-11-16 17:00:58.040 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.990497
2019-11-16 17:01:01.110 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:01.110 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:01.111 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:01.114 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.368124
2019-11-16 17:01:08.096 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:08.096 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:08.096 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:08.096 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:08.096 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:08.101 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=4.469484ms
2019-11-16 17:01:08.101 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=4.753251ms
2019-11-16 17:01:08.102 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.191537
2019-11-16 17:01:13.181 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:13.181 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:13.182 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:13.184 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.021353
2019-11-16 17:01:13.184 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:13.185 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:13.185 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:13.187 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.535144
2019-11-16 17:01:18.195 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:18.195 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:18.196 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:18.196 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:18.196 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:18.202 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=6.101213ms
2019-11-16 17:01:18.202 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=5.482356ms
2019-11-16 17:01:18.202 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.0267159999999995
2019-11-16 17:01:28.412 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:28.412 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:28.412 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:28.413 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:28.413 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:28.415 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.3114ms
2019-11-16 17:01:28.416 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=3.314781ms
2019-11-16 17:01:28.416 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.8383789999999998
2019-11-16 17:01:33.085 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:33.085 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:01:33.086 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:01:33.089 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.53976
2019-11-16 17:01:33.112 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:33.112 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:01:33.117 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:01:33.122 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=9.429053999999999
2019-11-16 17:01:38.537 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:38.537 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:38.537 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:38.537 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:38.537 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:38.540 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.526658ms
2019-11-16 17:01:38.540 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.770641ms
2019-11-16 17:01:38.540 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.4111800000000003
2019-11-16 17:01:45.181 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:45.181 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:01:45.182 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:01:45.184 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:01:45.186 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:01:45.189 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=7.898980999999999
2019-11-16 17:01:49.508 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:49.508 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:49.508 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:49.508 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:49.508 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:49.510 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.841486ms
2019-11-16 17:01:49.510 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.279061ms
2019-11-16 17:01:49.511 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.7883299999999998
2019-11-16 17:01:58.847 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.847 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="raw"
2019-11-16 17:01:58.849 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:01:58.852 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.444311
2019-11-16 17:01:58.874 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:58.874 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="raw"
2019-11-16 17:01:58.876 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:01:58.879 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.329485999999999
2019-11-16 17:01:59.108 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:59.109 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="refresh timer" table="mangle"
2019-11-16 17:01:59.111 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:01:59.114 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.713437
2019-11-16 17:01:59.300 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:59.301 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="mangle"
2019-11-16 17:01:59.302 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:01:59.307 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=6.530063
2019-11-16 17:01:59.328 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:59.329 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="refresh timer" table="nat"
2019-11-16 17:01:59.330 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:01:59.332 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.742764
2019-11-16 17:01:59.937 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:01:59.937 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:01:59.937 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:01:59.937 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:01:59.937 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:01:59.939 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.105919ms
2019-11-16 17:01:59.939 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.374117ms
2019-11-16 17:01:59.940 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.86057
2019-11-16 17:02:10.546 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:10.546 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:10.546 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:10.546 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:10.546 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:10.548 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.613178ms
2019-11-16 17:02:10.548 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.706615ms
2019-11-16 17:02:10.549 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.415024
2019-11-16 17:02:20.916 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:20.916 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:20.916 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:20.916 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:20.916 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:20.917 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.138721ms
2019-11-16 17:02:20.917 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.018644ms
2019-11-16 17:02:20.918 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=1.586297
2019-11-16 17:02:31.874 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:31.874 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:31.874 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:31.874 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:31.874 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:31.876 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.845901ms
2019-11-16 17:02:31.877 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.45568ms
2019-11-16 17:02:31.877 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.881228
2019-11-16 17:02:36.841 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.841 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="raw"
2019-11-16 17:02:36.843 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="raw"
2019-11-16 17:02:36.845 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.128261
2019-11-16 17:02:36.869 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:36.869 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="raw"
2019-11-16 17:02:36.871 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="raw"
2019-11-16 17:02:36.873 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.462983
2019-11-16 17:02:37.102 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:37.102 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="mangle"
2019-11-16 17:02:37.104 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="mangle"
2019-11-16 17:02:37.105 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.647828
2019-11-16 17:02:37.112 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:37.112 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="nat"
2019-11-16 17:02:37.113 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="nat"
2019-11-16 17:02:37.114 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.6559180000000002
2019-11-16 17:02:37.285 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:37.285 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="mangle"
2019-11-16 17:02:37.287 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="mangle"
2019-11-16 17:02:37.289 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.184097
2019-11-16 17:02:37.321 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:37.321 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="nat"
2019-11-16 17:02:37.322 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="nat"
2019-11-16 17:02:37.323 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.358355
2019-11-16 17:02:42.703 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:42.703 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:42.703 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:42.703 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:42.704 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:42.705 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.523044ms
2019-11-16 17:02:42.705 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.110161ms
2019-11-16 17:02:42.705 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.0093989999999997
2019-11-16 17:02:49.181 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:49.181 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x4 reason="post update" table="filter"
2019-11-16 17:02:49.182 [INFO][68] table.go 740: Invalidating dataplane cache ipVersion=0x6 reason="post update" table="filter"
2019-11-16 17:02:49.183 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x4 table="filter"
2019-11-16 17:02:49.185 [INFO][68] table.go 460: Loading current iptables state and checking it is correct. ipVersion=0x6 table="filter"
2019-11-16 17:02:49.187 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=5.7133009999999995
2019-11-16 17:02:53.039 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:02:53.039 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:02:53.040 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:02:53.040 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:02:53.040 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:02:53.042 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.430102ms
2019-11-16 17:02:53.042 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.997828ms
2019-11-16 17:02:53.043 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.0941699999999996
2019-11-16 17:03:03.242 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:03.242 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:03.242 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:03.242 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:03.242 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:03.244 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=1.520651ms
2019-11-16 17:03:03.245 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.361042ms
2019-11-16 17:03:03.245 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.886572
2019-11-16 17:03:10.131 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:10.131 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x4
2019-11-16 17:03:10.131 [INFO][68] route_table.go 189: Queueing a resync of routing table. ipVersion=0x6
2019-11-16 17:03:10.135 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=4.094826
2019-11-16 17:03:13.264 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:13.264 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:13.264 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:13.264 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:13.264 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:13.266 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.459124ms
2019-11-16 17:03:13.266 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.002386ms
2019-11-16 17:03:13.267 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.477578
2019-11-16 17:03:22.873 [INFO][68] usagerep.go 106: Initial delay complete, doing first report
2019-11-16 17:03:22.873 [INFO][68] usagerep.go 185: Reporting cluster usage/checking for deprecation warnings. alpEnabled=false calicoVersion="v3.3.2" clusterGUID="6e78891db03e4026a7766acf3b36b7b3" clusterType="k8s,bgp" gitRevision="1edd26adb1cfe5c6ff437467d429608428fbd1fe" stats=calc.StatsUpdate{NumHosts:3, NumWorkloadEndpoints:6, NumHostEndpoints:0, NumPolicies:0, NumProfiles:5, NumALPPolicies:0} version="v3.3.2"
2019-11-16 17:03:23.992 [INFO][68] usagerep.go 108: First report done, starting ticker
2019-11-16 17:03:24.030 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:24.031 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:24.031 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:24.031 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:24.031 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:24.033 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.06433ms
2019-11-16 17:03:24.033 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.457749ms
2019-11-16 17:03:24.033 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=2.810018
2019-11-16 17:03:34.288 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:34.288 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:34.289 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:34.289 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:34.289 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:34.291 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.03652ms
2019-11-16 17:03:34.291 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=2.683761ms
2019-11-16 17:03:34.292 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.1539430000000004
2019-11-16 17:03:44.773 [INFO][68] int_dataplane.go 751: Applying dataplane updates
2019-11-16 17:03:44.773 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet"
2019-11-16 17:03:44.773 [INFO][68] ipsets.go 223: Asked to resync with the dataplane on next update. family="inet6"
2019-11-16 17:03:44.773 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet"
2019-11-16 17:03:44.774 [INFO][68] ipsets.go 254: Resyncing ipsets with dataplane. family="inet6"
2019-11-16 17:03:44.775 [INFO][68] ipsets.go 304: Finished resync family="inet" numInconsistenciesFound=0 resyncDuration=1.931528ms
2019-11-16 17:03:44.777 [INFO][68] ipsets.go 304: Finished resync family="inet6" numInconsistenciesFound=0 resyncDuration=2.967926ms
2019-11-16 17:03:44.777 [INFO][68] int_dataplane.go 765: Finished applying updates to dataplane. msecToApply=3.780182
